-- Logs begin at Thu 2019-02-14 18:12:00 CST, end at Sat 2025-05-24 17:51:51 CST. -- May 24 17:50:07 volumio go-librespot[6560]: time="2025-05-24T17:50:07+08:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" May 24 17:50:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 24 17:50:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 24 17:50:07 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: Error: socket hang up May 24 17:50:07 volumio volumio[4955]: at connResetException (internal/errors.js:607:14) May 24 17:50:07 volumio volumio[4955]: at Socket.socketOnEnd (_http_client.js:493:23) May 24 17:50:07 volumio volumio[4955]: at Socket.emit (events.js:327:22) May 24 17:50:07 volumio volumio[4955]: at endReadableNT (internal/streams/readable.js:1327:12) May 24 17:50:07 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 24 17:50:07 volumio volumio[4955]: (node:4955) 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: 36) May 24 17:50:07 volumio volumio[4955]: info: Connection to go-librespot Websocket closed May 24 17:50:10 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:50:10 volumio volumio[4955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 24 17:50:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 24 17:50:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. May 24 17:50:10 volumio systemd[1]: Stopped go-librespot Daemon. May 24 17:50:10 volumio systemd[1]: Started go-librespot Daemon. May 24 17:50:10 volumio go-librespot[6658]: Librespot-go daemon starting... May 24 17:50:10 volumio go-librespot[6658]: time="2025-05-24T17:50:10+08:00" level=info msg="generated new device id: 195bf1c788bbc06ac879c1b7633f0b9c6613ef60" May 24 17:50:10 volumio go-librespot[6658]: time="2025-05-24T17:50:10+08:00" level=debug msg="stored credentials not found" May 24 17:50:12 volumio volumio[4955]: info: May 24 17:50:12 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:12 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:12 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:12 volumio volumio[4955]: info: May 24 17:50:12 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:12 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:12 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:12 volumio volumio[4955]: info: May 24 17:50:12 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:12 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:12 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:12 volumio volumio[4955]: info: sendMpdCommand status took 6 milliseconds May 24 17:50:12 volumio volumio[4955]: info: sendMpdCommand status took 6 milliseconds May 24 17:50:12 volumio volumio[4955]: info: sendMpdCommand status took 5 milliseconds May 24 17:50:12 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:12 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:12 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:12 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: CorePlayQueue::getTrack 0 May 24 17:50:12 volumio volumio[4955]: 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} May 24 17:50:12 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::syncState stateService stop May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus play May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::stPlaybackTimer May 24 17:50:12 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: CorePlayQueue::getTrack 0 May 24 17:50:12 volumio volumio[4955]: 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} May 24 17:50:12 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::syncState stateService stop May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus stop May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: No code May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: CorePlayQueue::getTrack 0 May 24 17:50:12 volumio volumio[4955]: 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} May 24 17:50:12 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::syncState stateService stop May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus stop May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: No code May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:12 volumio volumio[4955]: info: ------------------------------ 197ms May 24 17:50:12 volumio volumio[4955]: info: ------------------------------ 199ms May 24 17:50:12 volumio volumio[4955]: info: ------------------------------ 199ms May 24 17:50:12 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:12 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:12 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:12 volumio volumio[4955]: info: touch_display: Setting screensaver timeout to 15 seconds. May 24 17:50:13 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:50:13 volumio volumio[4955]: info: Connection to go-librespot Websocket established May 24 17:50:13 volumio go-librespot[6658]: time="2025-05-24T17:50:13+08:00" level=debug msg="new websocket client" May 24 17:50:15 volumio volumio[4955]: info: Clearing queue after UPNP request May 24 17:50:16 volumio volumio[4955]: info: CoreStateMachine::ClearQueue May 24 17:50:16 volumio volumio[4955]: info: CoreStateMachine::stop May 24 17:50:16 volumio volumio[4955]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 17:50:16 volumio volumio[4955]: info: CorePlayQueue::clearPlayQueue May 24 17:50:16 volumio volumio[4955]: info: CorePlayQueue::saveQueue May 24 17:50:16 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:16 volumio volumio[4955]: info: CoreCommandRouter::volumioPushQueue May 24 17:50:16 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: error: updateQueue error: null May 24 17:50:16 volumio volumio[4955]: error: updateQueue error: null May 24 17:50:16 volumio volumio[4955]: error: updateQueue error: null May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 8ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 8ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 7ms May 24 17:50:16 volumio volumio[4955]: info: Starting UPNP Playback May 24 17:50:16 volumio volumio[4955]: info: Preparing playback through UPNP May 24 17:50:16 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:16 volumio volumio[4955]: info: CorePlayQueue::getTrack 0 May 24 17:50:16 volumio volumio[4955]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 17:50:16 volumio volumio[4955]: info: Getting Spotify volume May 24 17:50:16 volumio volumio[4955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 May 24 17:50:16 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:16 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 3ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 3ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 1ms May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 1ms May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 8ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 7ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 6ms May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 1ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 1ms May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: May 24 17:50:16 volumio volumio[4955]: ---------------------------- MPD announces system playlist update May 24 17:50:16 volumio volumio[4955]: info: Ignoring MPD Status Update May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 1ms May 24 17:50:16 volumio volumio[4955]: info: ------------------------------ 2ms May 24 17:50:17 volumio volumio[4955]: info: May 24 17:50:17 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:17 volumio volumio[4955]: info: May 24 17:50:17 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:17 volumio volumio[4955]: info: May 24 17:50:17 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand status took 185 milliseconds May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 17:50:17 volumio volumio[4955]: info: May 24 17:50:17 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand status took 187 milliseconds May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 17:50:17 volumio volumio[4955]: info: May 24 17:50:17 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:17 volumio volumio[4955]: info: May 24 17:50:17 volumio volumio[4955]: ---------------------------- MPD announces state update: player May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::getState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand status May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand playlistinfo took 5 milliseconds May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand status took 5 milliseconds May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand playlistinfo took 4 milliseconds May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand playlistinfo took 3 milliseconds May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand status took 2 milliseconds May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseTrackInfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseTrackInfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseTrackInfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:17 volumio volumio[4955]: verbose: In UPNP mode May 24 17:50:17 volumio volumio[4955]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Aliens","artist":"Ganger Baster","album":"Aliens","uri":"http://m701.music.126.net/20250524181515/de51503ff2ddfdbe192d19774d2cb4a1/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/14212470228/839d/2c73/5d7a/2ac4fd1cdffe4b43a270480e62d9fa99.mp3?vuutv=Nv/KwzqZynV6XmfSdLf42bVz0t+HxTlsEm4+KuTZ4xBKlMk701McFgMQFQezKK6qjG0c86STQ/jqaXXhAkMmC6kBduxkkB6FIvdjkWauj7Q=","trackType":""} May 24 17:50:17 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState stateService play May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus stop May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:17 volumio volumio[4955]: verbose: In UPNP mode May 24 17:50:17 volumio volumio[4955]: verbose: STATE SERVICE {"status":"play","position":0,"seek":80,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Aliens","artist":"Ganger Baster","album":"Aliens","uri":"http://m701.music.126.net/20250524181515/de51503ff2ddfdbe192d19774d2cb4a1/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/14212470228/839d/2c73/5d7a/2ac4fd1cdffe4b43a270480e62d9fa99.mp3?vuutv=Nv/KwzqZynV6XmfSdLf42bVz0t+HxTlsEm4+KuTZ4xBKlMk701McFgMQFQezKK6qjG0c86STQ/jqaXXhAkMmC6kBduxkkB6FIvdjkWauj7Q=","trackType":""} May 24 17:50:17 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState stateService play May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus play May 24 17:50:17 volumio volumio[4955]: info: Received an update from plugin. extracting info from payload May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:17 volumio volumio[4955]: verbose: In UPNP mode May 24 17:50:17 volumio volumio[4955]: verbose: STATE SERVICE {"status":"play","position":0,"seek":137,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Aliens","artist":"Ganger Baster","album":"Aliens","uri":"http://m701.music.126.net/20250524181515/de51503ff2ddfdbe192d19774d2cb4a1/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/14212470228/839d/2c73/5d7a/2ac4fd1cdffe4b43a270480e62d9fa99.mp3?vuutv=Nv/KwzqZynV6XmfSdLf42bVz0t+HxTlsEm4+KuTZ4xBKlMk701McFgMQFQezKK6qjG0c86STQ/jqaXXhAkMmC6kBduxkkB6FIvdjkWauj7Q=","trackType":""} May 24 17:50:17 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState stateService play May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus play May 24 17:50:17 volumio volumio[4955]: info: Received an update from plugin. extracting info from payload May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: ------------------------------ 221ms May 24 17:50:17 volumio volumio[4955]: info: ------------------------------ 295ms May 24 17:50:17 volumio volumio[4955]: info: ------------------------------ 303ms May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand status took 115 milliseconds May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand playlistinfo took 113 milliseconds May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand playlistinfo took 112 milliseconds May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseState May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseTrackInfo May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseTrackInfo May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:17 volumio volumio[4955]: verbose: In UPNP mode May 24 17:50:17 volumio volumio[4955]: verbose: STATE SERVICE {"status":"play","position":0,"seek":731,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Aliens","artist":"Ganger Baster","album":"Aliens","uri":"http://m701.music.126.net/20250524181515/de51503ff2ddfdbe192d19774d2cb4a1/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/14212470228/839d/2c73/5d7a/2ac4fd1cdffe4b43a270480e62d9fa99.mp3?vuutv=Nv/KwzqZynV6XmfSdLf42bVz0t+HxTlsEm4+KuTZ4xBKlMk701McFgMQFQezKK6qjG0c86STQ/jqaXXhAkMmC6kBduxkkB6FIvdjkWauj7Q=","trackType":""} May 24 17:50:17 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState stateService play May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus play May 24 17:50:17 volumio volumio[4955]: info: Received an update from plugin. extracting info from payload May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:17 volumio volumio[4955]: verbose: In UPNP mode May 24 17:50:17 volumio volumio[4955]: verbose: STATE SERVICE {"status":"play","position":0,"seek":731,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Aliens","artist":"Ganger Baster","album":"Aliens","uri":"http://m701.music.126.net/20250524181515/de51503ff2ddfdbe192d19774d2cb4a1/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/14212470228/839d/2c73/5d7a/2ac4fd1cdffe4b43a270480e62d9fa99.mp3?vuutv=Nv/KwzqZynV6XmfSdLf42bVz0t+HxTlsEm4+KuTZ4xBKlMk701McFgMQFQezKK6qjG0c86STQ/jqaXXhAkMmC6kBduxkkB6FIvdjkWauj7Q=","trackType":""} May 24 17:50:17 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState stateService play May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus play May 24 17:50:17 volumio volumio[4955]: info: Received an update from plugin. extracting info from payload May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: ------------------------------ 219ms May 24 17:50:17 volumio volumio[4955]: info: ------------------------------ 217ms May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: info: sendMpdCommand playlistinfo took 178 milliseconds May 24 17:50:17 volumio volumio[4955]: verbose: ControllerMpd::parseTrackInfo May 24 17:50:17 volumio volumio[4955]: info: ControllerMpd::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::servicePushState May 24 17:50:17 volumio volumio[4955]: verbose: In UPNP mode May 24 17:50:17 volumio volumio[4955]: verbose: STATE SERVICE {"status":"play","position":0,"seek":731,"duration":136,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Aliens","artist":"Ganger Baster","album":"Aliens","uri":"http://m701.music.126.net/20250524181515/de51503ff2ddfdbe192d19774d2cb4a1/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/14212470228/839d/2c73/5d7a/2ac4fd1cdffe4b43a270480e62d9fa99.mp3?vuutv=Nv/KwzqZynV6XmfSdLf42bVz0t+HxTlsEm4+KuTZ4xBKlMk701McFgMQFQezKK6qjG0c86STQ/jqaXXhAkMmC6kBduxkkB6FIvdjkWauj7Q=","trackType":""} May 24 17:50:17 volumio volumio[4955]: verbose: CURRENT POSITION 0 May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState stateService play May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::syncState currentStatus play May 24 17:50:17 volumio volumio[4955]: info: Received an update from plugin. extracting info from payload May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::pushState May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioPushState May 24 17:50:17 volumio volumio[4955]: info: ------------------------------ 339ms May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: info: CoreCommandRouter::volumioGetQueue May 24 17:50:17 volumio volumio[4955]: info: CoreStateMachine::getQueue May 24 17:50:17 volumio volumio[4955]: info: CorePlayQueue::getQueue May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:17 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:39 volumio volumio[4955]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Miracle%20Of%20Sound/Valhalla%20Calling/843c010f-b214-47ae-a181-e5e1479cc6d5.jpg' May 24 17:50:40 volumio volumio[4955]: verbose: New Socket.io Connection to 192.168.2.10 from 192.168.2.8 UA: Mozilla/5.0 (Linux; Android 15; 23127PN0CC Build/AQ3A.240627.003; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.86 Mobile Safari/537.36 Total Clients: 9 May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::volumioGetVisibleSources May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 24 17:50:40 volumio volumio[4955]: info: Received Get System Info May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 24 17:50:40 volumio volumio[4955]: info: Discovery: Getting this device information May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 24 17:50:40 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:40 volumio volumio[4955]: info: Listing playlists May 24 17:50:40 volumio go-librespot[6658]: time="2025-05-24T17:50:40+08:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" May 24 17:50:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 24 17:50:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 24 17:50:40 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: Error: socket hang up May 24 17:50:40 volumio volumio[4955]: at connResetException (internal/errors.js:607:14) May 24 17:50:40 volumio volumio[4955]: at Socket.socketOnEnd (_http_client.js:493:23) May 24 17:50:40 volumio volumio[4955]: at Socket.emit (events.js:327:22) May 24 17:50:40 volumio volumio[4955]: at endReadableNT (internal/streams/readable.js:1327:12) May 24 17:50:40 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 24 17:50:40 volumio volumio[4955]: (node:4955) 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: 37) May 24 17:50:40 volumio volumio[4955]: info: Connection to go-librespot Websocket closed May 24 17:50:43 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:50:43 volumio volumio[4955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 24 17:50:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 24 17:50:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. May 24 17:50:43 volumio systemd[1]: Stopped go-librespot Daemon. May 24 17:50:44 volumio systemd[1]: Started go-librespot Daemon. May 24 17:50:44 volumio go-librespot[6820]: Librespot-go daemon starting... May 24 17:50:44 volumio go-librespot[6820]: time="2025-05-24T17:50:44+08:00" level=info msg="generated new device id: 4f50954d8655f571935b560d07a52996639f592a" May 24 17:50:44 volumio go-librespot[6820]: time="2025-05-24T17:50:44+08:00" level=debug msg="stored credentials not found" May 24 17:50:46 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:50:46 volumio go-librespot[6820]: time="2025-05-24T17:50:46+08:00" level=debug msg="new websocket client" May 24 17:50:46 volumio volumio[4955]: info: Connection to go-librespot Websocket established May 24 17:50:47 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:49 volumio volumio[4955]: info: Getting Spotify volume May 24 17:50:49 volumio volumio[4955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 May 24 17:50:49 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:50:49 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:50:52 volumio volumio[4955]: info: CALLMETHOD: user_interface peppy_screensaver saveVUMeterConf [object Object] May 24 17:50:52 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , saveVUMeterConf May 24 17:50:52 volumio volumio[4955]: info: CoreCommandRouter::getUIConfigOnPlugin May 24 17:50:52 volumio volumio[4955]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 24 17:50:55 volumio volumio[4955]: info: peppy_screensaver: Start PeppyMeter May 24 17:51:04 volumio volumio[4955]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 May 24 17:51:04 volumio volumio[4955]: info: touch_display: Setting screensaver timeout to 15 seconds. May 24 17:51:05 volumio volumio[4955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 9 May 24 17:51:05 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:51:14 volumio go-librespot[6820]: time="2025-05-24T17:51:14+08:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" May 24 17:51:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 24 17:51:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 24 17:51:14 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: Error: socket hang up May 24 17:51:14 volumio volumio[4955]: at connResetException (internal/errors.js:607:14) May 24 17:51:14 volumio volumio[4955]: at Socket.socketOnEnd (_http_client.js:493:23) May 24 17:51:14 volumio volumio[4955]: at Socket.emit (events.js:327:22) May 24 17:51:14 volumio volumio[4955]: at endReadableNT (internal/streams/readable.js:1327:12) May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 24 17:51:14 volumio volumio[4955]: (node:4955) 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: 38) May 24 17:51:14 volumio volumio[4955]: info: Connection to go-librespot Websocket closed May 24 17:51:14 volumio volumio[4955]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask: May 24 17:51:14 volumio volumio[4955]: LoungeScreenDisconnected { May 24 17:51:14 volumio volumio[4955]: AID: null, May 24 17:51:14 volumio volumio[4955]: name: 'loungeScreenDisconnected', May 24 17:51:14 volumio volumio[4955]: payload: {} May 24 17:51:14 volumio volumio[4955]: } May 24 17:51:14 volumio volumio[4955]: (IncompleteAPIDataError) Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } May 24 17:51:14 volumio volumio[4955]: Stack trace: May 24 17:51:14 volumio volumio[4955]: IncompleteAPIDataError: Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) May 24 17:51:14 volumio volumio[4955]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) May 24 17:51:14 volumio volumio[4955]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) May 24 17:51:14 volumio volumio[4955]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) May 24 17:51:14 volumio volumio[4955]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined May 24 17:51:14 volumio volumio[4955]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) 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: 40) May 24 17:51:14 volumio volumio[4955]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask: May 24 17:51:14 volumio volumio[4955]: LoungeScreenDisconnected { May 24 17:51:14 volumio volumio[4955]: AID: null, May 24 17:51:14 volumio volumio[4955]: name: 'loungeScreenDisconnected', May 24 17:51:14 volumio volumio[4955]: payload: {} May 24 17:51:14 volumio volumio[4955]: } May 24 17:51:14 volumio volumio[4955]: (IncompleteAPIDataError) Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } May 24 17:51:14 volumio volumio[4955]: Stack trace: May 24 17:51:14 volumio volumio[4955]: IncompleteAPIDataError: Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) May 24 17:51:14 volumio volumio[4955]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) May 24 17:51:14 volumio volumio[4955]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) May 24 17:51:14 volumio volumio[4955]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) May 24 17:51:14 volumio volumio[4955]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined May 24 17:51:14 volumio volumio[4955]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) 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: 42) May 24 17:51:14 volumio volumio[4955]: error: [yt-cast-receiver] (YouTube) Error occurred in SendMessageTask: May 24 17:51:14 volumio volumio[4955]: LoungeScreenDisconnected { May 24 17:51:14 volumio volumio[4955]: AID: null, May 24 17:51:14 volumio volumio[4955]: name: 'loungeScreenDisconnected', May 24 17:51:14 volumio volumio[4955]: payload: {} May 24 17:51:14 volumio volumio[4955]: } May 24 17:51:14 volumio volumio[4955]: (IncompleteAPIDataError) Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } May 24 17:51:14 volumio volumio[4955]: Stack trace: May 24 17:51:14 volumio volumio[4955]: IncompleteAPIDataError: Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) May 24 17:51:14 volumio volumio[4955]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) May 24 17:51:14 volumio volumio[4955]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) May 24 17:51:14 volumio volumio[4955]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) May 24 17:51:14 volumio volumio[4955]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined May 24 17:51:14 volumio volumio[4955]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) 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: 44) May 24 17:51:14 volumio volumio[4955]: error: [yt-cast-receiver] (YouTube Music) Error occurred in SendMessageTask: May 24 17:51:14 volumio volumio[4955]: LoungeScreenDisconnected { May 24 17:51:14 volumio volumio[4955]: AID: null, May 24 17:51:14 volumio volumio[4955]: name: 'loungeScreenDisconnected', May 24 17:51:14 volumio volumio[4955]: payload: {} May 24 17:51:14 volumio volumio[4955]: } May 24 17:51:14 volumio volumio[4955]: (IncompleteAPIDataError) Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: Error info: { missing: [ 'loungeIdToken', 'SID', 'gsessionid' ] } May 24 17:51:14 volumio volumio[4955]: Stack trace: May 24 17:51:14 volumio volumio[4955]: IncompleteAPIDataError: Missing data required to construct query string from bind params May 24 17:51:14 volumio volumio[4955]: at BindParams.toQueryString (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/BindParams.js:120:19) May 24 17:51:14 volumio volumio[4955]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:492:103) May 24 17:51:14 volumio volumio[4955]: at SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:71) May 24 17:51:14 volumio volumio[4955]: at AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:36) May 24 17:51:14 volumio volumio[4955]: at Session.end (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:237:71) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'removeAllListeners' of undefined May 24 17:51:14 volumio volumio[4955]: at Session._Session_refreshLoungeToken (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:372:16) May 24 17:51:14 volumio volumio[4955]: at runMicrotasks () May 24 17:51:14 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 24 17:51:14 volumio volumio[4955]: (node:4955) 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: 46) May 24 17:51:17 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:51:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 24 17:51:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. May 24 17:51:17 volumio systemd[1]: Stopped go-librespot Daemon. May 24 17:51:17 volumio volumio[4955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 24 17:51:17 volumio systemd[1]: Started go-librespot Daemon. May 24 17:51:17 volumio go-librespot[6944]: Librespot-go daemon starting... May 24 17:51:17 volumio go-librespot[6944]: time="2025-05-24T17:51:17+08:00" level=info msg="generated new device id: ddc672da34227ef2d7dc573b1c06fc890a83cd40" May 24 17:51:17 volumio go-librespot[6944]: time="2025-05-24T17:51:17+08:00" level=debug msg="stored credentials not found" May 24 17:51:20 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:51:20 volumio go-librespot[6944]: time="2025-05-24T17:51:20+08:00" level=debug msg="new websocket client" May 24 17:51:20 volumio volumio[4955]: info: Connection to go-librespot Websocket established May 24 17:51:23 volumio volumio[4955]: info: Getting Spotify volume May 24 17:51:23 volumio volumio[4955]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 May 24 17:51:23 volumio volumio[4955]: info: CoreCommandRouter::volumioGetState May 24 17:51:23 volumio volumio[4955]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 17:51:47 volumio go-librespot[6944]: time="2025-05-24T17:51:47+08:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" May 24 17:51:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 24 17:51:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 24 17:51:47 volumio volumio[4955]: (node:4955) UnhandledPromiseRejectionWarning: Error: socket hang up May 24 17:51:47 volumio volumio[4955]: at connResetException (internal/errors.js:607:14) May 24 17:51:47 volumio volumio[4955]: at Socket.socketOnEnd (_http_client.js:493:23) May 24 17:51:47 volumio volumio[4955]: at Socket.emit (events.js:327:22) May 24 17:51:47 volumio volumio[4955]: at endReadableNT (internal/streams/readable.js:1327:12) May 24 17:51:47 volumio volumio[4955]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 24 17:51:47 volumio volumio[4955]: (node:4955) 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: 47) May 24 17:51:47 volumio volumio[4955]: info: Connection to go-librespot Websocket closed May 24 17:51:50 volumio volumio[4955]: info: Initializing connection to go-librespot Websocket May 24 17:51:50 volumio volumio[4955]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 24 17:51:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 24 17:51:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. May 24 17:51:50 volumio systemd[1]: Stopped go-librespot Daemon. May 24 17:51:50 volumio systemd[1]: Started go-librespot Daemon. May 24 17:51:50 volumio go-librespot[7071]: Librespot-go daemon starting... May 24 17:51:50 volumio go-librespot[7071]: time="2025-05-24T17:51:50+08:00" level=info msg="generated new device id: 051cf08d6900029a32a4f1c9163040660f6af5b5" May 24 17:51:50 volumio go-librespot[7071]: time="2025-05-24T17:51:50+08:00" level=debug msg="stored credentials not found" May 24 17:51:50 volumio volumio[4955]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 17:51:50 volumio volumio[4955]: Error: connect ETIMEDOUT 199.16.156.103:443 May 24 17:51:50 volumio volumio[4955]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { May 24 17:51:50 volumio volumio[4955]: errno: -110, May 24 17:51:50 volumio volumio[4955]: code: 'ETIMEDOUT', May 24 17:51:50 volumio volumio[4955]: syscall: 'connect', May 24 17:51:50 volumio volumio[4955]: address: '199.16.156.103', May 24 17:51:50 volumio volumio[4955]: port: 443 May 24 17:51:50 volumio volumio[4955]: } May 24 17:51:50 volumio volumio[4955]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 17:51:51 volumio sudo[7091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-24 17:50 May 24 17:51:51 volumio sudo[7091]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"