-- Logs begin at Mon 2024-11-25 15:47:55 +03, end at Mon 2024-11-25 18:12:03 +03. -- Nov 25 18:11:00 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:00 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50660. Nov 25 18:11:02 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:02 volumio volumio[717]: info: Preload queue cleared Nov 25 18:11:02 volumio volumio[717]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::ClearQueue Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::stop Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::clearPlayQueue Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::saveQueue Nov 25 18:11:02 volumio volumio[717]: info: CoreCommandRouter::volumioPushQueue Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::addQueueItems Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::addQueueItems Nov 25 18:11:02 volumio volumio[717]: info: Preload queue cleared Nov 25 18:11:02 volumio volumio[717]: info: Adding Item to queue: spotify:track:4qACml9p54JYU4IIVkMDkW Nov 25 18:11:02 volumio volumio[717]: info: Using cached record of: spotify:track:4qACml9p54JYU4IIVkMDkW Nov 25 18:11:02 volumio volumio[717]: info: CoreCommandRouter::volumioPushQueue Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::saveQueue Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::updateTrackBlock Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::getTrackBlock Nov 25 18:11:02 volumio volumio[717]: info: CoreCommandRouter::volumioPlay Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::play index 0 Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::stop Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::play index undefined Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:02 volumio volumio[717]: info: CoreStateMachine::startPlaybackTimer Nov 25 18:11:02 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:02 volumio volumio[717]: info: [1732547462296] ControllerSpotify::clearAddPlayTrack Nov 25 18:11:02 volumio volumio[717]: info: Sending Spotify command with payload to local API: /player/play Nov 25 18:11:02 volumio volumio[717]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:02 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:02 volumio go-librespot[8778]: Librespot-go daemon starting... Nov 25 18:11:02 volumio go-librespot[8778]: time="2024-11-25T18:11:02+03:00" level=info msg="generated new device id: 0943f7e575a5851a97bfee288173e8aa7cf99a90" Nov 25 18:11:02 volumio go-librespot[8778]: time="2024-11-25T18:11:02+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:02 volumio go-librespot[8778]: time="2024-11-25T18:11:02+03:00" level=debug msg="obtained new client token: AADO+f/Njcyj/Tgy1QjI4O7TLX/VpERqBXcmZ6+7PVAlRirM7CewSLDWDZV0dsMEplhu0mabgElBYyrKKqpcoUSA2AR4z6NkKFRlGy84sPqCxj/QtzSUnEz+dRgH1lEoWDWgYoA/h7lwkzrE8/biMFh3BD/fonNpglvJUgbzgpRilVFNry2Owb0RJisysJYXDI7+0rWp4887ScAKzmjsE7enuem+JowF4tWvUyOxECsNjXM+khpQm+JLpWsx43E=" Nov 25 18:11:02 volumio go-librespot[8778]: time="2024-11-25T18:11:02+03: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]" Nov 25 18:11:03 volumio go-librespot[8778]: time="2024-11-25T18:11:03+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:03 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:03 volumio go-librespot[8778]: time="2024-11-25T18:11:03+03:00" level=debug msg="new websocket client" Nov 25 18:11:03 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:03 volumio go-librespot[8778]: time="2024-11-25T18:11:03+03:00" level=debug msg="completed challenge" Nov 25 18:11:03 volumio go-librespot[8778]: time="2024-11-25T18:11:03+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:03 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:11:06 volumio volumio[717]: info: Getting Spotify volume Nov 25 18:11:06 volumio volumio[717]: (node:717) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:06 volumio volumio[717]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 25 18:11:06 volumio volumio[717]: (node:717) 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: 32100) Nov 25 18:11:06 volumio volumio[717]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 25 18:11:06 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:06 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:06 volumio volumio[717]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 25 18:11:06 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:06 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50661. Nov 25 18:11:06 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:07 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:07 volumio go-librespot[8789]: Librespot-go daemon starting... Nov 25 18:11:07 volumio go-librespot[8789]: time="2024-11-25T18:11:07+03:00" level=info msg="generated new device id: fa334fb8121148837c89291de09ad6392eea71c6" Nov 25 18:11:07 volumio go-librespot[8789]: time="2024-11-25T18:11:07+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:07 volumio go-librespot[8789]: time="2024-11-25T18:11:07+03:00" level=debug msg="obtained new client token: AAAbh5YSQ4pzc2Wnes0DNOjwNGloS26Ex/CptSjN0olY2vvKIWFZAXmY02jWyWjdO63W6e4NUOYWJzxJEidcf1Ra+MJ3E1KVQna+MBaozHk/PmK+JlbcPPeDUnJsw1ZrRFPdy4haDsiagwocOv1p7/jcQ/gneQW80FvdTU2xZOzy4nDme7oD4dEAKA6GEFSYpNyxm62L5NmxdFnwPxWSUMhvqlBpt8WEvfMPJt5jSC2JLWFj4lKhAI2Z6uCqXFM=" Nov 25 18:11:07 volumio go-librespot[8789]: time="2024-11-25T18:11:07+03: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]" Nov 25 18:11:07 volumio go-librespot[8789]: time="2024-11-25T18:11:07+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:08 volumio go-librespot[8789]: time="2024-11-25T18:11:08+03:00" level=debug msg="completed challenge" Nov 25 18:11:08 volumio go-librespot[8789]: time="2024-11-25T18:11:08+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:09 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:09 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 18:11:11 volumio volumio[717]: info: Retrieving Cloud Streaming UI Nov 25 18:11:11 volumio volumio[717]: info: Getting Tidal Cloud Configuration Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 18:11:11 volumio volumio[717]: info: Getting Qobuz Cloud Configuration Nov 25 18:11:11 volumio volumio[717]: info: Asking plugin for UI Config Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 18:11:11 volumio volumio[717]: info: Getting Spotify Cloud Configuration Nov 25 18:11:11 volumio volumio[717]: info: Asking plugin for UI Config Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 18:11:11 volumio volumio[717]: info: Saving Spotify Acccount Nov 25 18:11:11 volumio volumio[717]: info: Got Tidal Cloud Configuration Nov 25 18:11:11 volumio volumio[717]: info: Got it Nov 25 18:11:11 volumio volumio[717]: info: Got it Nov 25 18:11:11 volumio volumio[717]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 18:11:11 volumio volumio[717]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::volumioGetBrowseSources Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::volumioGetBrowseSources Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::volumioGetBrowseSources Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:11 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Nov 25 18:11:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50662. Nov 25 18:11:11 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:11 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:11 volumio go-librespot[8812]: Librespot-go daemon starting... Nov 25 18:11:11 volumio go-librespot[8812]: time="2024-11-25T18:11:11+03:00" level=info msg="generated new device id: b06bfe8133ba040410525e83cd94e145fc287ce9" Nov 25 18:11:11 volumio go-librespot[8812]: time="2024-11-25T18:11:11+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:12 volumio go-librespot[8812]: time="2024-11-25T18:11:12+03:00" level=debug msg="obtained new client token: AADOpUbswlDu3/oQ43fRS3+TQdh5kue8z1refxTX8ipokAiV7sPBKVvF4i2mx2QxTZfYuoGY6flbvJgCBTDKktJb9oPma5vAYtzvM2iX8d06liXHwnXPZaHAX9eWKqXDLT6Fkdq9NtmXth2DAQSG8kIWGI0vdjCcUy6fag9P3XtxdluSs/cX/C1tyhDYKSHs+He82UV9d3bsSx+WBVQq0dMXwAuhxFDHuCM7M2pRwutCg6hrraLe6HQ/zV/T" Nov 25 18:11:12 volumio go-librespot[8812]: time="2024-11-25T18:11:12+03: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]" Nov 25 18:11:12 volumio go-librespot[8812]: time="2024-11-25T18:11:12+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:12 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:12 volumio go-librespot[8812]: time="2024-11-25T18:11:12+03:00" level=debug msg="new websocket client" Nov 25 18:11:12 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:13 volumio go-librespot[8812]: time="2024-11-25T18:11:13+03:00" level=debug msg="completed challenge" Nov 25 18:11:13 volumio go-librespot[8812]: time="2024-11-25T18:11:13+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:13 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:11:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:15 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:15 volumio volumio[717]: info: Getting Spotify volume Nov 25 18:11:15 volumio volumio[717]: (node:717) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:15 volumio volumio[717]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 25 18:11:15 volumio volumio[717]: (node:717) 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: 32101) Nov 25 18:11:15 volumio volumio[717]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 25 18:11:15 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:15 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:15 volumio volumio[717]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 25 18:11:16 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:16 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50663. Nov 25 18:11:16 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:16 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 18:11:16 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 18:11:16 volumio volumio[717]: info: Discovery: Getting this device information Nov 25 18:11:16 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:16 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:16 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 18:11:16 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:16 volumio go-librespot[8825]: Librespot-go daemon starting... Nov 25 18:11:16 volumio go-librespot[8825]: time="2024-11-25T18:11:16+03:00" level=info msg="generated new device id: 4e60c5bb7d610c214174ce1f1c2bb56433d566db" Nov 25 18:11:16 volumio go-librespot[8825]: time="2024-11-25T18:11:16+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:17 volumio go-librespot[8825]: time="2024-11-25T18:11:17+03:00" level=debug msg="obtained new client token: AABCPYjwwg5nbRzvHQLgibsLjo3CmPHw2X3Y9nbuhdCDgBAKcoRA+0LUWjCM9hMbEAzy4YDEEhoKq97oEu1QHqVInd9PFQegKmMj4T9EjugdY/QVe1+bLaUfTBy6F3dd2qfR+/LgLRRrDK6c/S2dITa2AX90NOhJLOBZtX5v7YJa5WdniOA57jWtpC3H393A2XMbagNyC3d90qXDoJ92vceVdlg2IvpK4eQNsarz4EOIApHwnV5e9zmtig==" Nov 25 18:11:17 volumio go-librespot[8825]: time="2024-11-25T18:11:17+03: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]" Nov 25 18:11:17 volumio go-librespot[8825]: time="2024-11-25T18:11:17+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:17 volumio go-librespot[8825]: time="2024-11-25T18:11:17+03:00" level=debug msg="completed challenge" Nov 25 18:11:17 volumio go-librespot[8825]: time="2024-11-25T18:11:17+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:19 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:19 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:19 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50664. Nov 25 18:11:20 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:21 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:21 volumio go-librespot[8847]: Librespot-go daemon starting... Nov 25 18:11:21 volumio go-librespot[8847]: time="2024-11-25T18:11:21+03:00" level=info msg="generated new device id: 550f3f450fe702bb383e58d2eabb68e8940c480a" Nov 25 18:11:21 volumio go-librespot[8847]: time="2024-11-25T18:11:21+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:21 volumio go-librespot[8847]: time="2024-11-25T18:11:21+03:00" level=debug msg="obtained new client token: AAAwMZZiRINhkWZhR92MsdGgZGB7t4r8wv5nu+HjisEHZdhOAoFlHpwh28zbWJNoD7tLX0jJOlgwElWOFqFnXiOXp8avE1Xo0HZC1VOJN8PG+5XpcVfZlgZDSqNY6SFrywgZ3jOp5L8vN445EEQZWYMKaazJcbrkmIsM7/M9sYP6ltqp2BohpXxqxCZIYu1MRmi7dWwugsFwZx+u3TZ/BPZFv+RQ0Iw2UNinlR8aIhaWPqNCtlCkk9TmLhFxT2Y=" Nov 25 18:11:21 volumio go-librespot[8847]: time="2024-11-25T18:11:21+03: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]" Nov 25 18:11:21 volumio go-librespot[8847]: time="2024-11-25T18:11:21+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:22 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:22 volumio go-librespot[8847]: time="2024-11-25T18:11:22+03:00" level=debug msg="new websocket client" Nov 25 18:11:22 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:22 volumio go-librespot[8847]: time="2024-11-25T18:11:22+03:00" level=debug msg="completed challenge" Nov 25 18:11:22 volumio go-librespot[8847]: time="2024-11-25T18:11:22+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:22 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:11:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:23 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:25 volumio volumio[717]: info: Getting Spotify volume Nov 25 18:11:25 volumio volumio[717]: (node:717) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:25 volumio volumio[717]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 25 18:11:25 volumio volumio[717]: (node:717) 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: 32102) Nov 25 18:11:25 volumio volumio[717]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 25 18:11:25 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:25 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:25 volumio volumio[717]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 25 18:11:25 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:25 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50665. Nov 25 18:11:25 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:25 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:25 volumio go-librespot[8858]: Librespot-go daemon starting... Nov 25 18:11:25 volumio go-librespot[8858]: time="2024-11-25T18:11:25+03:00" level=info msg="generated new device id: a58da813206a26181da6244d723d763f157df2be" Nov 25 18:11:25 volumio go-librespot[8858]: time="2024-11-25T18:11:25+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:26 volumio go-librespot[8858]: time="2024-11-25T18:11:26+03:00" level=debug msg="obtained new client token: AAAsN8LsRdOUoXjXGeFN39TAtwj1BIMSkqeXIjywc6EVq1P+zRGH3Kuphs6vssO83qslyKJGH77jlVvj6VtJYEXsinb/eo0jeBF5pan1ujN05ZUZAJauJdqiOAowqakIRubpruJ3Wop/k332lGhcndlH8gXX97PbQ6XdiH17Y20VjJx/HW1Nelu6fykx1P7ieBX3vchVKBkQkvKRczICiJcu8bU4uCQrtjWdLPYrLDSbuJlZYvcbefCy7vw+" Nov 25 18:11:26 volumio go-librespot[8858]: time="2024-11-25T18:11:26+03: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]" Nov 25 18:11:26 volumio go-librespot[8858]: time="2024-11-25T18:11:26+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:27 volumio go-librespot[8858]: time="2024-11-25T18:11:27+03:00" level=debug msg="completed challenge" Nov 25 18:11:27 volumio go-librespot[8858]: time="2024-11-25T18:11:27+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:27 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:28 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:28 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50666. Nov 25 18:11:30 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:30 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:30 volumio go-librespot[8866]: Librespot-go daemon starting... Nov 25 18:11:30 volumio go-librespot[8866]: time="2024-11-25T18:11:30+03:00" level=info msg="generated new device id: 086528225de9fc34d6e8458128f849ec37b05e64" Nov 25 18:11:30 volumio go-librespot[8866]: time="2024-11-25T18:11:30+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:30 volumio go-librespot[8866]: time="2024-11-25T18:11:30+03:00" level=debug msg="obtained new client token: AADkhbUvKyZS+lp038eYz8wkqXe+mLf6zWcFqe8QqzDGo5kGM0zsHY9W31TEVWjBX8DUNzmjw0C1E7nwp9JtrgTHBPOUK68shKjIQcPmp+A6dpwfgthLdfRXQm96n/DlIK7Kr0prU6QfSGvhvp1jvCNXh/rI29hhWXoG0pwj0rSj4mZ1oMdg38x7rWGMkLupYNaEUcO7Cz/uxIYqLW2xuQjT9GW3jA8eXPbfk8Rjnd2wkVC1al3KDaNcrvUcOTw=" Nov 25 18:11:30 volumio go-librespot[8866]: time="2024-11-25T18:11:30+03: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]" Nov 25 18:11:31 volumio go-librespot[8866]: time="2024-11-25T18:11:31+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:31 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:31 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:31 volumio go-librespot[8866]: time="2024-11-25T18:11:31+03:00" level=debug msg="new websocket client" Nov 25 18:11:31 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:31 volumio go-librespot[8866]: time="2024-11-25T18:11:31+03:00" level=debug msg="completed challenge" Nov 25 18:11:31 volumio go-librespot[8866]: time="2024-11-25T18:11:31+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:31 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:11:34 volumio volumio[717]: info: Getting Spotify volume Nov 25 18:11:34 volumio volumio[717]: (node:717) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:34 volumio volumio[717]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 25 18:11:34 volumio volumio[717]: (node:717) 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: 32103) Nov 25 18:11:34 volumio volumio[717]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 25 18:11:34 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:34 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:34 volumio volumio[717]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 25 18:11:34 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:34 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50667. Nov 25 18:11:34 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:35 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:35 volumio go-librespot[8892]: Librespot-go daemon starting... Nov 25 18:11:35 volumio go-librespot[8892]: time="2024-11-25T18:11:35+03:00" level=info msg="generated new device id: c3346cc50e9bcd9db3ce10eb501e449e23a79570" Nov 25 18:11:35 volumio go-librespot[8892]: time="2024-11-25T18:11:35+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:35 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:35 volumio go-librespot[8892]: time="2024-11-25T18:11:35+03:00" level=debug msg="obtained new client token: AAAPsomJa8cRJTeoH98mXWmlvfOxVtq7tyY3j8ABPE5s0hepL0D+gcRSxD3LSbyq1nQKck2Jvhr1ZSjxgrT0eZifPLTZ+yyczrpBUJveGsieiuH43RF8Q+1x4mMH+Ohh66+xSg+2+CVJjWmsSn9FaMsavd42jRVH4O6yaurH7CX45qMn3HKV/Tx2ftUPZah0R1ofEpgsC6DIa5yPJjj3DJnylobb9c39gSf0DNRGgX8GDOP8r975RG0EF8fOCnk=" Nov 25 18:11:35 volumio go-librespot[8892]: time="2024-11-25T18:11:35+03: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]" Nov 25 18:11:35 volumio go-librespot[8892]: time="2024-11-25T18:11:35+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:36 volumio go-librespot[8892]: time="2024-11-25T18:11:36+03:00" level=debug msg="completed challenge" Nov 25 18:11:36 volumio go-librespot[8892]: time="2024-11-25T18:11:36+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:37 volumio volumio[717]: verbose: New Socket.io Connection to 192.168.1.100 from 192.168.1.114 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::volumioGetVisibleSources Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:37 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::volumioGetQueue Nov 25 18:11:37 volumio volumio[717]: info: CoreStateMachine::getQueue Nov 25 18:11:37 volumio volumio[717]: info: CorePlayQueue::getQueue Nov 25 18:11:37 volumio volumio[717]: info: Listing playlists Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 25 18:11:37 volumio volumio[717]: info: Received Get System Info Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 18:11:37 volumio volumio[717]: info: Discovery: Getting this device information Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:37 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:37 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:37 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:37 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:37 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 25 18:11:39 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50668. Nov 25 18:11:39 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:39 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:39 volumio go-librespot[8938]: Librespot-go daemon starting... Nov 25 18:11:39 volumio go-librespot[8938]: time="2024-11-25T18:11:39+03:00" level=info msg="generated new device id: 487c3ac4bca963906f02946e517c69b5080d9bbb" Nov 25 18:11:39 volumio go-librespot[8938]: time="2024-11-25T18:11:39+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:40 volumio go-librespot[8938]: time="2024-11-25T18:11:40+03:00" level=debug msg="obtained new client token: AAAvB91oM999UkwF0Ov1Z3xQ73UEC4piuW/NSosW2VrZtjizqiFFlGLHPwQ/cWziOx/G4C7wTaV6v3gyIPxajokbaYB6zLnHScgWRUlFfCQ6gV95h+m1oYDIh0CPbkqGBSf8nVY02uXQArbWUiTQSPanLuA8GxzwSvMd75W5BQa8WKfq7XCkQxCspN/dHykfXi/kuhV5XcvFG4IBIH+2vFLKA2YdoqgR0WwpRp3DWrgl9nEJ3MBkUO3/79E6" Nov 25 18:11:40 volumio go-librespot[8938]: time="2024-11-25T18:11:40+03: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]" Nov 25 18:11:40 volumio go-librespot[8938]: time="2024-11-25T18:11:40+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:40 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:40 volumio go-librespot[8938]: time="2024-11-25T18:11:40+03:00" level=debug msg="new websocket client" Nov 25 18:11:40 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:41 volumio go-librespot[8938]: time="2024-11-25T18:11:41+03:00" level=debug msg="completed challenge" Nov 25 18:11:41 volumio go-librespot[8938]: time="2024-11-25T18:11:41+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:41 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:11:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:43 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:43 volumio volumio[717]: info: Getting Spotify volume Nov 25 18:11:43 volumio volumio[717]: (node:717) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:43 volumio volumio[717]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 25 18:11:43 volumio volumio[717]: (node:717) 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: 32104) Nov 25 18:11:43 volumio volumio[717]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 25 18:11:43 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:43 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:43 volumio volumio[717]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 25 18:11:44 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:44 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50669. Nov 25 18:11:44 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:44 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:44 volumio go-librespot[8963]: Librespot-go daemon starting... Nov 25 18:11:44 volumio go-librespot[8963]: time="2024-11-25T18:11:44+03:00" level=info msg="generated new device id: 2a4636e17b9d225f39a8a85b0a8af07ccb0972fb" Nov 25 18:11:44 volumio go-librespot[8963]: time="2024-11-25T18:11:44+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:45 volumio go-librespot[8963]: time="2024-11-25T18:11:45+03:00" level=debug msg="obtained new client token: AAAhkfINUtMqkVsepEq7uZhlDk+ws5Eit1RU000Vc3AK2CKscVB45UHfWCSaPz+pjkGhUbDdtgOV7nHYdn9ZKgAXBeec3/zhY5uj9p3hxu27wIIPHm6wUkhD1/ou0ZgtDgR2+bk1bpuj4FNSnmJMp16YHXZkHjxuphcRll6OxcpgLinwFEIo9Nycv/Xalhu2WWno0688HxIeMDpycGl70chdRu/QUQsKgI4V/R+83BJbpDOE3TdqwMpL7P07" Nov 25 18:11:45 volumio go-librespot[8963]: time="2024-11-25T18:11:45+03: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]" Nov 25 18:11:45 volumio go-librespot[8963]: time="2024-11-25T18:11:45+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:45 volumio go-librespot[8963]: time="2024-11-25T18:11:45+03:00" level=debug msg="completed challenge" Nov 25 18:11:46 volumio go-librespot[8963]: time="2024-11-25T18:11:46+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:46 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 18:11:46 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 18:11:46 volumio volumio[717]: info: Discovery: Getting this device information Nov 25 18:11:46 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:46 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:46 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 18:11:47 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:47 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:47 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:47 volumio volumio[717]: info: CALLMETHOD: music_service mpd saveMusicLibraryOptions [object Object] Nov 25 18:11:47 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , saveMusicLibraryOptions Nov 25 18:11:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50670. Nov 25 18:11:49 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:49 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:49 volumio go-librespot[8971]: Librespot-go daemon starting... Nov 25 18:11:49 volumio go-librespot[8971]: time="2024-11-25T18:11:49+03:00" level=info msg="generated new device id: 49ea3eab312a6dd3610312523c5cf20ff09f8c70" Nov 25 18:11:49 volumio go-librespot[8971]: time="2024-11-25T18:11:49+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:49 volumio go-librespot[8971]: time="2024-11-25T18:11:49+03:00" level=debug msg="obtained new client token: AABWu8H1iw9monCmcwC5OLzP8DYphvFzC5H4uVH0xCULPmQzedhwtWnYR6gEI4PdyTnsXx/HmTGlRkALxChGlqT7jfI/aLYXkGPYglMr+spBGtV3aJ+KifgdZXKMW98D4p8ZJ/1vo4bCGkyKVLR0gtZVhYGN/SRCmNeSftvSqURYWrd1BfivGne07BD5aI5X82ZveFxEg7tqduNNxNgdXoQL9jrRX75LtCQmprvrwR11pfrZS+H4QH7ZK5UyTVI=" Nov 25 18:11:49 volumio go-librespot[8971]: time="2024-11-25T18:11:49+03: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]" Nov 25 18:11:50 volumio go-librespot[8971]: time="2024-11-25T18:11:50+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:50 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:50 volumio go-librespot[8971]: time="2024-11-25T18:11:50+03:00" level=debug msg="new websocket client" Nov 25 18:11:50 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:50 volumio volumio[717]: info: CALLMETHOD: miscellanea my_music updateMusicLibraryBrowseSourcesVisibility [object Object] Nov 25 18:11:50 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibraryBrowseSourcesVisibility Nov 25 18:11:50 volumio volumio[717]: info: CoreCommandRouter::volumioUpdateToBrowseSources Nov 25 18:11:50 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 25 18:11:50 volumio volumio[717]: Cannot find translation for source Spotify Nov 25 18:11:50 volumio go-librespot[8971]: time="2024-11-25T18:11:50+03:00" level=debug msg="completed challenge" Nov 25 18:11:50 volumio go-librespot[8971]: time="2024-11-25T18:11:50+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:50 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:11:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:51 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:52 volumio volumio[717]: info: CALLMETHOD: miscellanea my_music updateMusicLibrarySupersearchSources [object Object] Nov 25 18:11:52 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibrarySupersearchSources Nov 25 18:11:53 volumio volumio[717]: info: CoreCommandRouter::volumioGetBrowseSources Nov 25 18:11:53 volumio volumio[717]: info: CoreCommandRouter::volumioGetBrowseSources Nov 25 18:11:53 volumio volumio[717]: info: CoreCommandRouter::updateGlobalSearchableBrowseSources Nov 25 18:11:53 volumio volumio[717]: info: Getting Spotify volume Nov 25 18:11:53 volumio volumio[717]: (node:717) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:53 volumio volumio[717]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 25 18:11:53 volumio volumio[717]: (node:717) 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: 32105) Nov 25 18:11:53 volumio volumio[717]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 25 18:11:53 volumio volumio[717]: info: CoreCommandRouter::volumioGetState Nov 25 18:11:53 volumio volumio[717]: info: CorePlayQueue::getTrack 0 Nov 25 18:11:53 volumio volumio[717]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 25 18:11:53 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:53 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:53 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50671. Nov 25 18:11:53 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:54 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:54 volumio go-librespot[8997]: Librespot-go daemon starting... Nov 25 18:11:54 volumio go-librespot[8997]: time="2024-11-25T18:11:54+03:00" level=info msg="generated new device id: 9dd7725b2c666f9741525b8bf806210386eda211" Nov 25 18:11:54 volumio go-librespot[8997]: time="2024-11-25T18:11:54+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:54 volumio go-librespot[8997]: time="2024-11-25T18:11:54+03:00" level=debug msg="obtained new client token: AABRwLI3PdYcdNXl6INXKIV0SGUjdKXvp8VhZVmGM5/ehBZsi7q2HPMhmvlhXHv8acPvv5sdSk7CZidxtV0u7Hj6PbQBLT3p8rjSAz+EsiY6vK6iGqlzhKKOM+EGkM6/aqrDSnC2Gg7nOfNSn4jUL0/Wb9piVNfuwX7I99CjjguKP4gbrgrEL6iSHyT4tJYrAwceRZ/nXReIulP16smoI5KCpRRkzk8dzBvHnVfScZikg7VAR5KdtBKCsSrvRQU=" Nov 25 18:11:54 volumio go-librespot[8997]: time="2024-11-25T18:11:54+03: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]" Nov 25 18:11:54 volumio go-librespot[8997]: time="2024-11-25T18:11:54+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:55 volumio go-librespot[8997]: time="2024-11-25T18:11:55+03:00" level=debug msg="completed challenge" Nov 25 18:11:55 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:55 volumio go-librespot[8997]: time="2024-11-25T18:11:55+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:11:55 volumio volumio[717]: info: CALLMETHOD: miscellanea albumart saveAlbumartOptions [object Object] Nov 25 18:11:55 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: albumart , saveAlbumartOptions Nov 25 18:11:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:11:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:11:56 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:56 volumio volumio[717]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 25 18:11:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:11:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50672. Nov 25 18:11:58 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:11:58 volumio volumio[717]: info: Disabling MyMusic plugin upnp_browser Nov 25 18:11:58 volumio volumio[717]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesMedya Sunucuları Nov 25 18:11:58 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 25 18:11:58 volumio volumio[717]: Cannot find translation for source Spotify Nov 25 18:11:58 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:11:58 volumio go-librespot[9005]: Librespot-go daemon starting... Nov 25 18:11:58 volumio volumio[717]: info: Disabling plugin upnp_browser Nov 25 18:11:58 volumio volumio[717]: info: Done. Nov 25 18:11:58 volumio go-librespot[9005]: time="2024-11-25T18:11:58+03:00" level=info msg="generated new device id: fd3f3bce93d7e54e674037b0c1fc7e69a47771a4" Nov 25 18:11:58 volumio go-librespot[9005]: time="2024-11-25T18:11:58+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:11:59 volumio go-librespot[9005]: time="2024-11-25T18:11:59+03:00" level=debug msg="obtained new client token: AABHpGOjaINPYn/EhJbwlSklgEiUdiYYn6PlGFimMBo2SIECbM+6p2rgkrJtt4CYdqpBBzoqr5DSiq/jf6K9Y7TKdW64/rl2VmOyG45+GUBBpyOEAtI1WKSXOLHqVMbQJXYQtwkNzJ5i0dB544I542oh9uzYCZOMiymDZI1Fhs1GlszSMK/eQ9Y8tvhYN6SOBRRhmRybVszLmj9dGW/2sQK3E5ZIPAdhRpaaknTLtU4m6Z4pfeCV4/MR1zS3" Nov 25 18:11:59 volumio go-librespot[9005]: time="2024-11-25T18:11:59+03: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]" Nov 25 18:11:59 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 25 18:11:59 volumio go-librespot[9005]: time="2024-11-25T18:11:59+03:00" level=debug msg="completed keyexchange" Nov 25 18:11:59 volumio volumio[717]: info: Initializing connection to go-librespot Websocket Nov 25 18:11:59 volumio go-librespot[9005]: time="2024-11-25T18:11:59+03:00" level=debug msg="new websocket client" Nov 25 18:11:59 volumio volumio[717]: info: Connection to go-librespot Websocket established Nov 25 18:11:59 volumio volumio[717]: info: Enabling MyMusic plugin upnp_browser Nov 25 18:11:59 volumio volumio[717]: info: Enabling plugin upnp_browser Nov 25 18:11:59 volumio volumio[717]: info: Loading plugin "upnp_browser"... Nov 25 18:11:59 volumio volumio[717]: info: PLUGIN START: upnp_browser Nov 25 18:11:59 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 25 18:11:59 volumio volumio[717]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 25 18:11:59 volumio volumio[717]: info: [1732547519850] CoreMusicLibrary::Adding element Medya Sunucuları Nov 25 18:11:59 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 25 18:11:59 volumio volumio[717]: Cannot find translation for source Spotify Nov 25 18:11:59 volumio volumio[717]: info: Done. Nov 25 18:12:00 volumio go-librespot[9005]: time="2024-11-25T18:12:00+03:00" level=debug msg="completed challenge" Nov 25 18:12:00 volumio go-librespot[9005]: time="2024-11-25T18:12:00+03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Nov 25 18:12:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 25 18:12:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 25 18:12:00 volumio volumio[717]: info: Connection to go-librespot Websocket closed Nov 25 18:12:02 volumio volumio[717]: info: Disabling MyMusic plugin upnp Nov 25 18:12:02 volumio sudo[9029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Nov 25 18:12:02 volumio sudo[9029]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 18:12:02 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Nov 25 18:12:02 volumio volumio[717]: error: Upnp client error: Error: This socket has been ended by the other party Nov 25 18:12:02 volumio volumio[717]: info: Enabling MyMusic plugin upnp Nov 25 18:12:02 volumio volumio[717]: info: Enabling plugin upnp Nov 25 18:12:02 volumio volumio[717]: info: Loading plugin "upnp"... Nov 25 18:12:02 volumio volumio[717]: info: [1732547522770] Starting Upmpd Daemon Nov 25 18:12:02 volumio volumio[717]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 25 18:12:02 volumio volumio[717]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 18:12:02 volumio volumio[717]: Error: listen EADDRINUSE: address already in use :::6599 Nov 25 18:12:02 volumio volumio[717]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Nov 25 18:12:02 volumio volumio[717]: at listenInCluster (net.js:1366:12) Nov 25 18:12:02 volumio volumio[717]: at Server.listen (net.js:1452:7) Nov 25 18:12:02 volumio volumio[717]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Nov 25 18:12:02 volumio volumio[717]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Nov 25 18:12:02 volumio volumio[717]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 25 18:12:02 volumio volumio[717]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 25 18:12:02 volumio volumio[717]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Nov 25 18:12:02 volumio volumio[717]: code: 'EADDRINUSE', Nov 25 18:12:02 volumio volumio[717]: errno: -98, Nov 25 18:12:02 volumio volumio[717]: syscall: 'listen', Nov 25 18:12:02 volumio volumio[717]: address: '::', Nov 25 18:12:02 volumio volumio[717]: port: 6599 Nov 25 18:12:02 volumio volumio[717]: } Nov 25 18:12:02 volumio volumio[717]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 18:12:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 25 18:12:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50673. Nov 25 18:12:03 volumio systemd[1]: Stopped go-librespot Daemon. Nov 25 18:12:03 volumio systemd[1]: Started go-librespot Daemon. Nov 25 18:12:03 volumio go-librespot[9039]: Librespot-go daemon starting... Nov 25 18:12:03 volumio go-librespot[9039]: time="2024-11-25T18:12:03+03:00" level=info msg="generated new device id: bd6dbc24b777acc02b3f3a09ef333cf16f56fa68" Nov 25 18:12:03 volumio go-librespot[9039]: time="2024-11-25T18:12:03+03:00" level=debug msg="stored credentials found for 93v9rs98zcr0qh5f0prd4j96a" Nov 25 18:12:03 volumio sudo[9051]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-25 18:11 Nov 25 18:12:03 volumio sudo[9051]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"