-- Logs begin at Fri 2024-08-16 16:05:52 CEST, end at Fri 2024-08-16 22:25:30 CEST. -- Aug 16 22:24:00 volumio-slaapkamer volumiologrotate[629]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Aug 16 22:24:00 volumio-slaapkamer volumiologrotate[629]: ls: cannot access 'SLAAPKAMER': No such file or directory Aug 16 22:24:01 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:24:03 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:03 volumio-slaapkamer go-librespot[22487]: time="2024-08-16T22:24:03+02:00" level=debug msg="obtained new client token: AAAbbR26dIIRvWtFqerm/8/6WI2LkMZJUDpks84vJKBCikPn9p4XiLjIpyPL/eX4qB4fJkxI+fpqJG8xQKNdWnr+geAmho057IR3TYzhenHfJTS+wwlwdGKepJ11bFT8IoM+Wh3Zh350faN3byzS1IxnlsERWlCitZNadFreb2mKOjKCw/0xuW596nf/WTJDCGbbO/h9iCyBzI4y7c6Xw3nwS7+eUMKXuMlflfWAjc6VLVIF+aaEROhm04PUJaA=" Aug 16 22:24:03 volumio-slaapkamer go-librespot[22487]: time="2024-08-16T22:24:03+02:00" 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]" Aug 16 22:24:03 volumio-slaapkamer go-librespot[22487]: time="2024-08-16T22:24:03+02:00" level=debug msg="completed keyexchange" Aug 16 22:24:04 volumio-slaapkamer go-librespot[22487]: time="2024-08-16T22:24:04+02:00" level=debug msg="completed challenge" Aug 16 22:24:04 volumio-slaapkamer go-librespot[22487]: time="2024-08-16T22:24:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 16 22:24:04 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:24:04 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:24:07 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 16 22:24:07 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59309. Aug 16 22:24:07 volumio-slaapkamer systemd[1]: Stopped go-librespot Daemon. Aug 16 22:24:07 volumio-slaapkamer systemd[1]: Started go-librespot Daemon. Aug 16 22:24:07 volumio-slaapkamer go-librespot[22550]: Librespot-go daemon starting... Aug 16 22:24:07 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:07+02:00" level=info msg="generated new device id: 1a1287107bcbb45db96ed2d7f02a69c1fbef444a" Aug 16 22:24:07 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:07+02:00" level=debug msg="stored credentials found for 1151341159" Aug 16 22:24:12 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:12+02:00" level=debug msg="obtained new client token: AAA12VC91cryEho0LuOYGRuITtIHT2QoosGSBtRn5af3LicKScqWHNWz/C8fV3TWG4CmGGLiqep0bc4P6K4Wv8ZpiK24qYZX6xmgovJhcvPBx0l57CCahGgvIU63wq28C0JMxFmrJb3nMimBKrjwtjrNVFlNZJ6V1sZby6FZeuJCsPZ0RPDkPM0UthJQNplZPNB0HHQwfEAQA39x1hok7V7bXlpGOvIpHh/x23Bl44Yh2dGkXzF/2ctQH7W5zMk=" Aug 16 22:24:12 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:12+02:00" 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]" Aug 16 22:24:12 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:12+02:00" level=debug msg="completed keyexchange" Aug 16 22:24:13 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:13+02:00" level=debug msg="new websocket client" Aug 16 22:24:13 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket established Aug 16 22:24:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:13 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:24:13 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:24:13 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:13+02:00" level=debug msg="completed challenge" Aug 16 22:24:13 volumio-slaapkamer go-librespot[22550]: time="2024-08-16T22:24:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 16 22:24:13 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:24:13 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:24:13 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket closed Aug 16 22:24:16 volumio-slaapkamer volumio[952]: info: Getting Spotify volume Aug 16 22:24:16 volumio-slaapkamer volumio[952]: (node:952) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:24:16 volumio-slaapkamer volumio[952]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 16 22:24:16 volumio-slaapkamer volumio[952]: (node:952) 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: 8401) Aug 16 22:24:16 volumio-slaapkamer volumio[952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 16 22:24:16 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:16 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:24:16 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:24:16 volumio-slaapkamer volumio[952]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:24:16 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 16 22:24:16 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59310. Aug 16 22:24:16 volumio-slaapkamer systemd[1]: Stopped go-librespot Daemon. Aug 16 22:24:16 volumio-slaapkamer systemd[1]: Started go-librespot Daemon. Aug 16 22:24:16 volumio-slaapkamer go-librespot[22573]: Librespot-go daemon starting... Aug 16 22:24:16 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:16+02:00" level=info msg="generated new device id: 67f89e32a7d3189a8d2ec915d148f2577a7fb7a0" Aug 16 22:24:16 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:16+02:00" level=debug msg="stored credentials found for 1151341159" Aug 16 22:24:19 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:24:19 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket established Aug 16 22:24:19 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:19+02:00" level=debug msg="new websocket client" Aug 16 22:24:21 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:21+02:00" level=debug msg="obtained new client token: AAB29uPkFFpq0Gx1TipyY9ILRYs2qGxbors09K7DC+t5wnsr9F2ir0UJml8pZIvhw5/EXKCDWea0DqFm+dM7lIV4XcWZW6SOnKUnJ5jeAMxPWDXEGVXX1r9rg92XPvDhoi0KE3s/VDAIuY4b7I56dUsvmicAnO9InTqpdtgASJzIGqpiBJkW7L1fWFTf7wRlQZ0P7zSELuNMGixDAn/dO0yTW68M7EZtTfpQTfZaj643Div83ffo69ig6SiOokU=" Aug 16 22:24:21 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:21+02:00" 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]" Aug 16 22:24:21 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:21+02:00" level=debug msg="completed keyexchange" Aug 16 22:24:22 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:22+02:00" level=debug msg="completed challenge" Aug 16 22:24:22 volumio-slaapkamer volumio[952]: info: Getting Spotify volume Aug 16 22:24:22 volumio-slaapkamer volumio[952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 16 22:24:22 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:22 volumio-slaapkamer go-librespot[22573]: time="2024-08-16T22:24:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 16 22:24:22 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:24:22 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:24:22 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:24:22 volumio-slaapkamer volumio[952]: (node:952) UnhandledPromiseRejectionWarning: Error: socket hang up Aug 16 22:24:22 volumio-slaapkamer volumio[952]: at connResetException (internal/errors.js:607:14) Aug 16 22:24:22 volumio-slaapkamer volumio[952]: at Socket.socketOnEnd (_http_client.js:493:23) Aug 16 22:24:22 volumio-slaapkamer volumio[952]: at Socket.emit (events.js:327:22) Aug 16 22:24:22 volumio-slaapkamer volumio[952]: at endReadableNT (internal/streams/readable.js:1327:12) Aug 16 22:24:22 volumio-slaapkamer volumio[952]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Aug 16 22:24:22 volumio-slaapkamer volumio[952]: (node:952) 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: 8402) Aug 16 22:24:22 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket closed Aug 16 22:24:23 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:25 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:24:25 volumio-slaapkamer volumio[952]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:24:25 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 16 22:24:25 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59311. Aug 16 22:24:25 volumio-slaapkamer systemd[1]: Stopped go-librespot Daemon. Aug 16 22:24:25 volumio-slaapkamer systemd[1]: Started go-librespot Daemon. Aug 16 22:24:25 volumio-slaapkamer go-librespot[22595]: Librespot-go daemon starting... Aug 16 22:24:25 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:25+02:00" level=info msg="generated new device id: f06b0d55aec3fc163174c7e8a42b6226da59c960" Aug 16 22:24:25 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:25+02:00" level=debug msg="stored credentials found for 1151341159" Aug 16 22:24:25 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:25+02:00" level=debug msg="obtained new client token: AAADMRchF4vR4eMkH8x0JoEBWcZzuduo+srTTE2XY8//QjiYCOmH44MqYt865CMNkhMDawN+SUgulWCqOJglWi5EVIWCbsJi2bvoHy+AJigKeQG8Y9/D0bspXzNfktBvwdHeJJP+7FVjrJ5jHb13+fRyJ/8To+KtU7narJzYLkhe1lsdREvywTqzlAJzxn+Sd9FPOw5YyhyXRefgzcl5FBjNzZ/fjVNrU0CABKRxnTt05aRDR9SBP7h2Ryji3l4=" Aug 16 22:24:25 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:25+02:00" 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]" Aug 16 22:24:25 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:25+02:00" level=debug msg="completed keyexchange" Aug 16 22:24:26 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:26+02:00" level=debug msg="completed challenge" Aug 16 22:24:26 volumio-slaapkamer go-librespot[22595]: time="2024-08-16T22:24:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 16 22:24:26 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:24:26 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:24:28 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:24:28 volumio-slaapkamer volumio[952]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:24:29 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 16 22:24:29 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59312. Aug 16 22:24:29 volumio-slaapkamer systemd[1]: Stopped go-librespot Daemon. Aug 16 22:24:29 volumio-slaapkamer systemd[1]: Started go-librespot Daemon. Aug 16 22:24:29 volumio-slaapkamer go-librespot[22604]: Librespot-go daemon starting... Aug 16 22:24:29 volumio-slaapkamer go-librespot[22604]: time="2024-08-16T22:24:29+02:00" level=info msg="generated new device id: 7d7491f549d8e14b52481e2b4370b27dec805589" Aug 16 22:24:29 volumio-slaapkamer go-librespot[22604]: time="2024-08-16T22:24:29+02:00" level=debug msg="stored credentials found for 1151341159" Aug 16 22:24:31 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:24:31 volumio-slaapkamer go-librespot[22604]: time="2024-08-16T22:24:31+02:00" level=debug msg="new websocket client" Aug 16 22:24:31 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket established Aug 16 22:24:33 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:33 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:24:33 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:24:34 volumio-slaapkamer volumio[952]: info: Getting Spotify volume Aug 16 22:24:34 volumio-slaapkamer volumio[952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 16 22:24:34 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:34 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:24:43 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:53 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:24:53 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:24:53 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:24:57 volumio-slaapkamer go-librespot[22604]: time="2024-08-16T22:24:57+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Aug 16 22:24:57 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:24:57 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:24:57 volumio-slaapkamer volumio[952]: (node:952) UnhandledPromiseRejectionWarning: Error: socket hang up Aug 16 22:24:57 volumio-slaapkamer volumio[952]: at connResetException (internal/errors.js:607:14) Aug 16 22:24:57 volumio-slaapkamer volumio[952]: at Socket.socketOnEnd (_http_client.js:493:23) Aug 16 22:24:57 volumio-slaapkamer volumio[952]: at Socket.emit (events.js:327:22) Aug 16 22:24:57 volumio-slaapkamer volumio[952]: at endReadableNT (internal/streams/readable.js:1327:12) Aug 16 22:24:57 volumio-slaapkamer volumio[952]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Aug 16 22:24:57 volumio-slaapkamer volumio[952]: (node:952) 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: 8403) Aug 16 22:24:57 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket closed Aug 16 22:25:00 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:25:00 volumio-slaapkamer volumio[952]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:25:00 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 16 22:25:00 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59313. Aug 16 22:25:00 volumio-slaapkamer volumiologrotate[629]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Aug 16 22:25:00 volumio-slaapkamer systemd[1]: Stopped go-librespot Daemon. Aug 16 22:25:00 volumio-slaapkamer volumiologrotate[629]: ls: cannot access 'SLAAPKAMER': No such file or directory Aug 16 22:25:00 volumio-slaapkamer systemd[1]: Started go-librespot Daemon. Aug 16 22:25:00 volumio-slaapkamer go-librespot[22655]: Librespot-go daemon starting... Aug 16 22:25:00 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:00+02:00" level=info msg="generated new device id: e964106c5e7fa09de075cfc336859b65d21f4c7e" Aug 16 22:25:00 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:00+02:00" level=debug msg="stored credentials found for 1151341159" Aug 16 22:25:03 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:25:03 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:25:03 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:03+02:00" level=debug msg="new websocket client" Aug 16 22:25:03 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket established Aug 16 22:25:06 volumio-slaapkamer volumio[952]: info: Getting Spotify volume Aug 16 22:25:06 volumio-slaapkamer volumio[952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 16 22:25:06 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:25:06 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:25:11 volumio-slaapkamer volumio[952]: info: Clearing queue after UPNP request Aug 16 22:25:11 volumio-slaapkamer volumio[952]: verbose: UNSET VOLATILE: Service: multiroom Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::ClearQueue Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::stop Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::updateTrackBlock Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrackBlock Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::stPlaybackTimer Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::pushState Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioPushState Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output update for this device Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreStateMachine::serviceStop Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: ControllerMpd::stop Aug 16 22:25:12 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand stop Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CorePlayQueue::clearPlayQueue Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CorePlayQueue::saveQueue Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioPushState Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output update for this device Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioPushQueue Aug 16 22:25:12 volumio-slaapkamer volumio[952]: error: Upnp client error: Error: This socket has been ended by the other party Aug 16 22:25:12 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:25:12 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: MRS: Updating multiroomSync output Aug 16 22:25:12 volumio-slaapkamer volumio[952]: info: sendMpdCommand stop took 32 milliseconds Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: Listing playlists Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:13 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces state update: options Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: ControllerMpd::getState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand status Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: sendMpdCommand status took 3 milliseconds Aug 16 22:25:13 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: ControllerMpd::pushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::servicePushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreStateMachine::pushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioPushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output update for this device Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 16 22:25:13 volumio-slaapkamer volumio[952]: verbose: CURRENT POSITION 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState stateService stop Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState currentStatus stop Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreStateMachine::pushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioPushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output update for this device Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: No code Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreStateMachine::pushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioPushState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output update for this device Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: MRS: Pushing multiroomSync output Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: ------------------------------ 18ms Aug 16 22:25:13 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: Starting UPNP Playback Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: Preparing playback through UPNP Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:13 volumio-slaapkamer volumio[952]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:14 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: ------------------------------ 3ms Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:14 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: ------------------------------ 1ms Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:14 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: ------------------------------ 1ms Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:14 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: ------------------------------ 2ms Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:14 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: ------------------------------ 2ms Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:14 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:14 volumio-slaapkamer volumio[952]: info: ------------------------------ 2ms Aug 16 22:25:20 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:20+02:00" level=debug msg="obtained new client token: AABZSI7tzRsXvEEql5avqv91sNBTTKs6VbxSHo4SPW3JKrkH8MTW2zVpmjcm11dw+JXoh3s268Vnd50Lt1qrKtZVAxTux6vJoKvuDQTyh7JDTFzcp4yLwxLiEap+yGcxnbjatdlzM5AWu1NqeG3AMNr0xddGMxp8Uvx6NKctkDpUDB4xaWVSVPf1GWYVczFolu3QduiVQq/3QRIMSE5Y2dXK+INiAfUcsi2CPcCQX2bdmRyW9LeFfAtmDJGa" Aug 16 22:25:20 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:20+02:00" 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]" Aug 16 22:25:20 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:20+02:00" level=debug msg="completed keyexchange" Aug 16 22:25:20 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:20+02:00" level=debug msg="completed challenge" Aug 16 22:25:20 volumio-slaapkamer go-librespot[22655]: time="2024-08-16T22:25:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 16 22:25:20 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:25:20 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:25:20 volumio-slaapkamer volumio[952]: (node:952) UnhandledPromiseRejectionWarning: Error: socket hang up Aug 16 22:25:20 volumio-slaapkamer volumio[952]: at connResetException (internal/errors.js:607:14) Aug 16 22:25:20 volumio-slaapkamer volumio[952]: at Socket.socketOnEnd (_http_client.js:493:23) Aug 16 22:25:20 volumio-slaapkamer volumio[952]: at Socket.emit (events.js:327:22) Aug 16 22:25:20 volumio-slaapkamer volumio[952]: at endReadableNT (internal/streams/readable.js:1327:12) Aug 16 22:25:20 volumio-slaapkamer volumio[952]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Aug 16 22:25:20 volumio-slaapkamer volumio[952]: (node:952) 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: 8404) Aug 16 22:25:20 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket closed Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:22 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces state update: player Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ControllerMpd::getState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand status Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:22 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces state update: player Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: sendMpdCommand status took 7 milliseconds Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ControllerMpd::getState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand status Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: sendMpdCommand status took 2 milliseconds Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseTrackInfo Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ControllerMpd::pushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::servicePushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: In UPNP mode Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ugp_hdcxf44z","artist":"None","album":"None","uri":"http://192.168.178.29:8097/ugp/ugp_hdcxf44z.mp3?player_id=media_player.volumio_slaapkamer_upnp_av","trackType":""} Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: CURRENT POSITION 0 Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState stateService play Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState currentStatus stop Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ------------------------------ 12ms Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseTrackInfo Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ControllerMpd::pushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::servicePushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: In UPNP mode Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ugp_hdcxf44z","artist":"None","album":"None","uri":"http://192.168.178.29:8097/ugp/ugp_hdcxf44z.mp3?player_id=media_player.volumio_slaapkamer_upnp_av","trackType":""} Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: CURRENT POSITION 0 Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState stateService play Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState currentStatus play Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Received an update from plugin. extracting info from payload Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::pushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:22 volumio-slaapkamer volumio[952]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ------------------------------ 8ms Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:22 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces system playlist update Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Ignoring MPD Status Update Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Aug 16 22:25:22 volumio-slaapkamer volumio[952]: ---------------------------- MPD announces state update: player Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ControllerMpd::getState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand status Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ------------------------------ 3ms Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: sendMpdCommand status took 2 milliseconds Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: ControllerMpd::parseTrackInfo Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ControllerMpd::pushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::servicePushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: In UPNP mode Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1211,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"ugp_hdcxf44z.mp3?player_id=media_player.volumio_slaapkamer_upnp_av","artist":"Music Assistant","album":null,"uri":"http://192.168.178.29:8097/ugp/ugp_hdcxf44z.mp3?player_id=media_player.volumio_slaapkamer_upnp_av","trackType":""} Aug 16 22:25:22 volumio-slaapkamer volumio[952]: verbose: CURRENT POSITION 0 Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState stateService play Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::syncState currentStatus play Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: Received an update from plugin. extracting info from payload Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CoreStateMachine::pushState Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:22 volumio-slaapkamer volumio[952]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined Aug 16 22:25:22 volumio-slaapkamer volumio[952]: info: ------------------------------ 6ms Aug 16 22:25:23 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:25:23 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:23 volumio-slaapkamer volumio[952]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:107:28) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at /volumio/node_modules/express/lib/router/index.js:281:22 Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Aug 16 22:25:23 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:25:23 volumio-slaapkamer volumio[952]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:25:23 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 16 22:25:23 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59314. Aug 16 22:25:23 volumio-slaapkamer systemd[1]: Stopped go-librespot Daemon. Aug 16 22:25:23 volumio-slaapkamer systemd[1]: Started go-librespot Daemon. Aug 16 22:25:23 volumio-slaapkamer go-librespot[22749]: Librespot-go daemon starting... Aug 16 22:25:23 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:23+02:00" level=info msg="generated new device id: 9c5a89e8f28ee7a9302f2b446cde758a2bd7c798" Aug 16 22:25:23 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:23+02:00" level=debug msg="stored credentials found for 1151341159" Aug 16 22:25:26 volumio-slaapkamer volumio[952]: info: Initializing connection to go-librespot Websocket Aug 16 22:25:26 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:26+02:00" level=debug msg="new websocket client" Aug 16 22:25:26 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket established Aug 16 22:25:29 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:29+02:00" level=debug msg="obtained new client token: AAD2DL2vQx4oMv8qYiX0z8tq8y7N3McxGaI48GpJ6ydvohfgXePU2cgPb9cUx5FiN4Z9L+HmRGEHA25xOxzzEzmBQLx8FOf3/iGgeBhS7pe29EZ6ewqnF7z/uIO//iRRS6p+0U21KSgwwxqG3G71MWrAXwXntoZSF+Nm3FmW4X2hwPVc71n8Mw7qyoJFHCkCtZmYECJSjTt6Iae6RBikrk8Gi9DY9ZddnBaR+r2lxpBTlmT4E7lasmHzFmBN" Aug 16 22:25:29 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:29+02:00" 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]" Aug 16 22:25:29 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:29+02:00" level=debug msg="completed keyexchange" Aug 16 22:25:29 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:29+02:00" level=debug msg="completed challenge" Aug 16 22:25:29 volumio-slaapkamer go-librespot[22749]: time="2024-08-16T22:25:29+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Aug 16 22:25:29 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 16 22:25:29 volumio-slaapkamer systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 16 22:25:29 volumio-slaapkamer volumio[952]: info: Connection to go-librespot Websocket closed Aug 16 22:25:29 volumio-slaapkamer volumio[952]: info: Getting Spotify volume Aug 16 22:25:29 volumio-slaapkamer volumio[952]: (node:952) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: (node:952) 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: 8405) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 16 22:25:29 volumio-slaapkamer volumio[952]: info: CoreCommandRouter::volumioGetState Aug 16 22:25:29 volumio-slaapkamer volumio[952]: info: CorePlayQueue::getTrack 0 Aug 16 22:25:29 volumio-slaapkamer volumio[952]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 16 22:25:29 volumio-slaapkamer volumio[952]: TypeError: Cannot read property 'name' of undefined Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:107:28) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:58:38) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at Socket.emit (events.js:315:20) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Aug 16 22:25:29 volumio-slaapkamer volumio[952]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Aug 16 22:25:29 volumio-slaapkamer volumio[952]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 16 22:25:30 volumio-slaapkamer sudo[22769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-16 22:24 Aug 16 22:25:30 volumio-slaapkamer sudo[22769]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"