-- Logs begin at Mon 2025-01-13 22:02:07 CET, end at Mon 2025-01-13 22:17:06 CET. -- Jan 13 22:16:00 volumio volumio[816]: info: Jan 13 22:16:00 volumio volumio[816]: ---------------------------- MPD announces state update: player Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::getState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand status Jan 13 22:16:00 volumio volumio[816]: info: Jan 13 22:16:00 volumio volumio[816]: ---------------------------- MPD announces state update: player Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::getState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand status Jan 13 22:16:00 volumio volumio[816]: info: Jan 13 22:16:00 volumio volumio[816]: ---------------------------- MPD announces state update: player Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::getState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand status Jan 13 22:16:00 volumio volumio[816]: info: Jan 13 22:16:00 volumio volumio[816]: ---------------------------- MPD announces state update: player Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::getState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand status Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand status took 1 milliseconds Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand status took 1 milliseconds Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand status took 0 milliseconds Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand status took 0 milliseconds Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseState Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 13 22:16:00 volumio volumio[816]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseTrackInfo Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseTrackInfo Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseTrackInfo Jan 13 22:16:00 volumio volumio[816]: verbose: ControllerMpd::parseTrackInfo Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::servicePushState Jan 13 22:16:00 volumio volumio[816]: verbose: In UPNP mode Jan 13 22:16:00 volumio volumio[816]: verbose: STATE SERVICE {"status":"pause","position":2,"seek":225251,"duration":290,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1165 Kbps","isStreaming":false,"title":"Broken","artist":"Walter Trout","album":"Broken","uri":"https://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEicwZTk4N2I5MDhlZGZlM2M3ZjBlMzJjN2JkNzQzNDg5Y182MS5tcDQ/0.flac?token=1736806056~YTUxMjk0ZmY1OGM4MTczNDA2MWRiN2Q1ZWZhN2M0OTMwZGU1YWE5NQ==","trackType":"tidal"} Jan 13 22:16:00 volumio volumio[816]: verbose: CURRENT POSITION 0 Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState stateService pause Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState currentStatus play Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioPushState Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::stPlaybackTimer Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::servicePushState Jan 13 22:16:00 volumio volumio[816]: verbose: In UPNP mode Jan 13 22:16:00 volumio volumio[816]: verbose: STATE SERVICE {"status":"pause","position":2,"seek":225251,"duration":290,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1165 Kbps","isStreaming":false,"title":"Broken","artist":"Walter Trout","album":"Broken","uri":"https://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEicwZTk4N2I5MDhlZGZlM2M3ZjBlMzJjN2JkNzQzNDg5Y182MS5tcDQ/0.flac?token=1736806056~YTUxMjk0ZmY1OGM4MTczNDA2MWRiN2Q1ZWZhN2M0OTMwZGU1YWE5NQ==","trackType":"tidal"} Jan 13 22:16:00 volumio volumio[816]: verbose: CURRENT POSITION 0 Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState stateService pause Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState currentStatus play Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioPushState Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::stPlaybackTimer Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::servicePushState Jan 13 22:16:00 volumio volumio[816]: verbose: In UPNP mode Jan 13 22:16:00 volumio volumio[816]: verbose: STATE SERVICE {"status":"pause","position":2,"seek":225251,"duration":290,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1165 Kbps","isStreaming":false,"title":"Broken","artist":"Walter Trout","album":"Broken","uri":"https://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEicwZTk4N2I5MDhlZGZlM2M3ZjBlMzJjN2JkNzQzNDg5Y182MS5tcDQ/0.flac?token=1736806056~YTUxMjk0ZmY1OGM4MTczNDA2MWRiN2Q1ZWZhN2M0OTMwZGU1YWE5NQ==","trackType":"tidal"} Jan 13 22:16:00 volumio volumio[816]: verbose: CURRENT POSITION 0 Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState stateService pause Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState currentStatus play Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioPushState Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::stPlaybackTimer Jan 13 22:16:00 volumio volumio[816]: info: ControllerMpd::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::servicePushState Jan 13 22:16:00 volumio volumio[816]: verbose: In UPNP mode Jan 13 22:16:00 volumio volumio[816]: verbose: STATE SERVICE {"status":"pause","position":2,"seek":225251,"duration":290,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1165 Kbps","isStreaming":false,"title":"Broken","artist":"Walter Trout","album":"Broken","uri":"https://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEicwZTk4N2I5MDhlZGZlM2M3ZjBlMzJjN2JkNzQzNDg5Y182MS5tcDQ/0.flac?token=1736806056~YTUxMjk0ZmY1OGM4MTczNDA2MWRiN2Q1ZWZhN2M0OTMwZGU1YWE5NQ==","trackType":"tidal"} Jan 13 22:16:00 volumio volumio[816]: verbose: CURRENT POSITION 0 Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState stateService pause Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::syncState currentStatus play Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::pushState Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioPushState Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::stPlaybackTimer Jan 13 22:16:00 volumio volumio[816]: info: ------------------------------ 9ms Jan 13 22:16:00 volumio volumio[816]: info: ------------------------------ 10ms Jan 13 22:16:00 volumio volumio[816]: info: ------------------------------ 10ms Jan 13 22:16:00 volumio volumio[816]: info: ------------------------------ 9ms Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioGetQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CorePlayQueue::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioGetQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CorePlayQueue::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioGetQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CorePlayQueue::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreCommandRouter::volumioGetQueue Jan 13 22:16:00 volumio volumio[816]: info: CoreStateMachine::getQueue Jan 13 22:16:00 volumio volumio[816]: info: CorePlayQueue::getQueue Jan 13 22:16:00 volumio volumio[816]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jan 13 22:16:00 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:00 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 209. Jan 13 22:16:02 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:02 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:02 volumio go-librespot[7207]: Librespot-go daemon starting... Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=info msg="generated new device id: 6fbb8f7b664579a0173d51e9cbbb5450455bcb46" Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=debug msg="obtained new client token: AADDgxL1Q1Wx5aMojXf/D5bWAJ8MznNfFIQqKmv6pakrww6dcbXt0szIb8G4wSUrczt6PuJPSHYjR4R5nRAULRp8gpfspy4KX1sM6mdjQuQtmbIE71IP2Gcy8RU6sS2b6aIL0sWLWeCcOnA7i5+D55s7C4pGaghSH1isG1RcHJ9lQgzw6PbrYRpin02kWSYTo/CWpxSbJJD8CIf8bJXAY2gkwWaMVlFFLrr7obIquupWQZ16JyBRTZ67Tyw=" Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=debug msg="completed challenge" Jan 13 22:16:02 volumio go-librespot[7207]: time="2025-01-13T22:16:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:03 volumio ntpd[1568]: 194.57.169.1 local addr 192.168.1.16 -> Jan 13 22:16:03 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:03 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 210. Jan 13 22:16:06 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:06 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:06 volumio go-librespot[7232]: Librespot-go daemon starting... Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=info msg="generated new device id: 69e5ea06b9579f2505d04baa3810931362336755" Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=debug msg="obtained new client token: AAAGIxXIa0OKpqD4pCy0ib/7beLjbTAKh0MRGnaV1/LBHLJI0MsUD5Lz5j6Qngjy55dqKbeeOuZQVce5zs0U9dxbJ0vn/HB8+PRvVGLA2TFbSekNzjNS36205fCperjrXLKjK0HUld8UQQQOHKcW/62zBqvTx/Bt8UYyzyiExSdS1ZDXRPF8V2CS1EUbbfCKxN8t/wwrA/3XZMHy+UKgR9q8ioyl6fC2iS2ByZZLwB3tJUn2D9woJUHZLvo=" Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:06 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=debug msg="new websocket client" Jan 13 22:16:06 volumio volumio[816]: info: Connection to go-librespot Websocket established Jan 13 22:16:06 volumio go-librespot[7232]: time="2025-01-13T22:16:06+01:00" level=debug msg="completed challenge" Jan 13 22:16:07 volumio go-librespot[7232]: time="2025-01-13T22:16:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:07 volumio volumio[816]: info: Connection to go-librespot Websocket closed Jan 13 22:16:09 volumio volumio[816]: info: Getting Spotify volume Jan 13 22:16:09 volumio volumio[816]: (node:816) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:09 volumio volumio[816]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jan 13 22:16:09 volumio volumio[816]: (node:816) 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: 25) Jan 13 22:16:09 volumio volumio[816]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 13 22:16:09 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:09 volumio volumio[816]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jan 13 22:16:10 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:10 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 211. Jan 13 22:16:10 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:10 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:10 volumio go-librespot[7243]: Librespot-go daemon starting... Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=info msg="generated new device id: d01530cd74d8f4707aaf6ac0ce4045037b673602" Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=debug msg="obtained new client token: AADRLVrH/PhbZ+RrfQLUhA7RYAieoUB0a1jFpiB/Mm3RvidXGq3sxPZvQx9b41+sLJ4bAanhjyVmu46IDNB5x47GKF5XuUoy4vmlospqSruGBKXDFoI63K4cUpA73aw14yKIiBMIhQDsFTKeYDlREgCR8/JCoVrvBUWyIOJkMIfPtLAocYNf87ys48sUvG5CEtz88SzxJ42WiJd/Ms2JBUlFqe+kgzK3uCFjjjQQJVmuhc/K4gWeWjzcTK0=" Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=debug msg="completed challenge" Jan 13 22:16:10 volumio go-librespot[7243]: time="2025-01-13T22:16:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:13 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:13 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 212. Jan 13 22:16:14 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:14 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:14 volumio go-librespot[7295]: Librespot-go daemon starting... Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=info msg="generated new device id: d198acd9dd2309e7619c68ecf732aee6ba9cdb21" Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=debug msg="obtained new client token: AACpdVci/9Vh5meMsofJlneIzDLZ+cthHOWhUUl2ERPqb+VLZKPPAOqO33zI88rzrH2AbzQ2A2pXzItqDerTykwYL6sT4/LIfnPxbwUHfj+8r1BLaDG1RzpHPG44YJ3hCYYXBVf9GgODownGJGckZ1ggI/913Z5gv0F6voqZbs5lyfumDj3urvC2bFb9iabBrpkD/kX35a5rwXC17Nu6L7u64fFKPrWhbc5iMuHS1G3I2kfYsLpydFtsSw0=" Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=debug msg="completed challenge" Jan 13 22:16:14 volumio go-librespot[7295]: time="2025-01-13T22:16:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:16 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:16 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 213. Jan 13 22:16:18 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:18 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:18 volumio go-librespot[7320]: Librespot-go daemon starting... Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=info msg="generated new device id: c24c7307c72a9d25df970fbbbfba79a5dd16c079" Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=debug msg="obtained new client token: AADPIV8k3lDjnBA2EbR6abNMqWwBKOf9rejuVnVqXMyaDIexfzrZtvTCku3q8BXz8N7nYzdNmZbI/MHASiR4JVu6lnPLd2etp9Lb47iRwuJ0/noxZFz4yc3ynzXY9UB9DwNzv768ygNVlmPZmSIuZh2FbQyn9iZVZ53F1ivS9255qOvDLHGLtTIzm33gLFDFfY8s3iybJ/CBTO13FL7I+KNZdXXTHN9/s+x2eTYLFmIgmxJYc9aenvt0ZGc=" Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:18 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:18 volumio volumio[816]: verbose: New Socket.io Connection to 192.168.1.16:3000 from 192.168.1.22 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 13 22:16:18 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=debug msg="completed challenge" Jan 13 22:16:18 volumio go-librespot[7320]: time="2025-01-13T22:16:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:19 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:19 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:22 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:22 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 214. Jan 13 22:16:22 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:22 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:22 volumio go-librespot[7329]: Librespot-go daemon starting... Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=info msg="generated new device id: 38bfe4762300b9f6e84f316e321b703a3470da64" Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=debug msg="obtained new client token: AAAtCIjJ4NWrgOFLKYmTznQwsDJNz2WMFHiOA5NLkSGVygF00SdqZqcKTQwZCkuA4NZQOWZhVuxZBbqdmIEfE3zJv6N9rTpT9N/pfncpPwzGnXP07KBL8uyAe64MFh0rc7RAh6l4rmE+etPa2JSvLXukoWVIHnpMtNj2fH1J5b08O4hlW21EATHOS0mCYHcscokn2RsijAb5SfGIDIu2fgGqdHzND/UlGBu0bVq1lSre7KkJCIKCTJWQBBc=" Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:22 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:22 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:22 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:22 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:22 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=debug msg="completed challenge" Jan 13 22:16:22 volumio go-librespot[7329]: time="2025-01-13T22:16:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:24 volumio sudo[7339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 22:16:24 volumio sudo[7339]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:24 volumio sudo[7339]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:24 volumio sudo[7342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 22:16:24 volumio sudo[7342]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:24 volumio sudo[7342]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:24 volumio volumio[816]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.22 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.201 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 13 22:16:24 volumio sudo[7361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 13 22:16:24 volumio sudo[7361]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:24 volumio sudo[7361]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:24 volumio sudo[7364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 13 22:16:24 volumio sudo[7364]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:24 volumio sudo[7364]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:25 volumio volumio[816]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.22 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.201 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jan 13 22:16:25 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:25 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::volumioGetVisibleSources Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 13 22:16:25 volumio volumio[816]: info: Received Get System Info Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:25 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:25 volumio volumio[816]: info: Listing playlists Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 13 22:16:25 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 13 22:16:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 215. Jan 13 22:16:26 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:26 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:26 volumio go-librespot[7368]: Librespot-go daemon starting... Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=info msg="generated new device id: 0f463d5ad6a70859c476ebf8d6c728bc4d6c6398" Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=debug msg="obtained new client token: AABpqZJS/Yfn0qSB9ju+wFGePh1YIdw5yF36oWYZnUEbx/0b8ia6awng9hofAWMj3qxZBK9CAuuzmlXMrX2Mq+zfP2upa216ORYLvqLj2il5Z4kYJxqFCB5FWB8FYmmFlC00FofX2mtP2keEuwdhvA+8KiAcsrHFykEaNeaycz+CTURUIeEOe7CTE+HgNrQRyVUo9/xf8NO0yFDICxAxZJPlvcfobxjLNPlbjz95nC4Fo178diY0df0SGa8=" Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:26 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 22:16:26 volumio volumio[816]: info: Received Get System Info Jan 13 22:16:26 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:26 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:26 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:26 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:26 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=debug msg="completed challenge" Jan 13 22:16:26 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 13 22:16:26 volumio go-librespot[7368]: time="2025-01-13T22:16:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 13 22:16:27 volumio volumio[816]: info: Received Get System Info Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:27 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:27 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:28 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:28 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 216. Jan 13 22:16:30 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:30 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:30 volumio go-librespot[7384]: Librespot-go daemon starting... Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=info msg="generated new device id: 155c0a56017f434e1281c51fa53a34df57d9355a" Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=debug msg="obtained new client token: AAAWAWH9yK5TPaqJZeoIThLRMvo7+nOiCDzMGadthIX3U625J8is+narwBFGNbDpBCaiYbBVPgULCUFdUygNvcpeR+y4UytJ9wUK114wWaEAgwf51y3ozuoVgl73ORShHT2IHsHH9ikaz4a9FP/6hMvrboGI3yS5OP1+kRa3CX+ood4UU0Upxb0plz2zWE8xBrt8Dtg4v8rn9Y+QDulh+O14DdVMygSpD1ceZfVnhKpgXFXQjMTTCiZtEc4=" Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=debug msg="completed challenge" Jan 13 22:16:30 volumio go-librespot[7384]: time="2025-01-13T22:16:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:31 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:31 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:34 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:34 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 217. Jan 13 22:16:34 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:34 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:34 volumio go-librespot[7392]: Librespot-go daemon starting... Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=info msg="generated new device id: 973e57cc979c6641db4c3e37b4867e20af50d33c" Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=debug msg="obtained new client token: AADxOIsFvngWt8WtWLRWyXKIaSHJQbvaFX6md/4OZnX16CVAuhAOdoCLSRk9ESTLy0EqtX8o/pN2Jf2Phefa9L3NIQ9UYIei/CsfPEZhlFIQgOn9fMGfi5xWW2XaF7aWsqR5q7af3ALsh5LYOVJc52vqcSOhBThFQh1LMDJjB3ePC/PLSH69JPTqpcBIn+jTvg/5ot0vyr9of931VRjbk7kUG68krp5WFRGn+G1+LtIsq3OFfINQmU1IVK8=" Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=debug msg="completed challenge" Jan 13 22:16:34 volumio go-librespot[7392]: time="2025-01-13T22:16:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:34 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 13 22:16:37 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:37 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 218. Jan 13 22:16:38 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:38 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:38 volumio go-librespot[7417]: Librespot-go daemon starting... Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=info msg="generated new device id: ad30043e0dc75a3f328cb7a0a67d4a015eeda69b" Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=debug msg="obtained new client token: AAAEQ4Djt4MaFeICKSfbnWIm2Rh5KlyIyDv70bREOa1lWjRbQESp+lwsmQnmJSQFHvYO1uxEC7jl8tfIRqA+JNBWMUnbnkTqle6bfhyhPBuTDubnGJergEp3xLVxFIN4FM5eDzNZNyIhWBcxHplTkIREXsOnVqKzj/q9AXzJRRVdNQuD4j1wEzkGRRncoyVLjR49pDRQWVV1TYIhQFvPP3LdJpbixOmb8TJoij4B4JMg+f+ft0FfZgU0eRQ=" Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=debug msg="completed challenge" Jan 13 22:16:38 volumio go-librespot[7417]: time="2025-01-13T22:16:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:40 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:40 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 219. Jan 13 22:16:42 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:42 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:42 volumio go-librespot[7425]: Librespot-go daemon starting... Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=info msg="generated new device id: d16e67f7af4cd85eb1797fb01afa5fbd432c45bf" Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=debug msg="obtained new client token: AADEurjEwGu16yj8kcpctqVcUs6Jfz0h0PSdF8lFV9lKbzGp9nmFhjyD6TfxGarUUVy5rZMKFSGlWIcjRiBGBJErRPlSPpfLL20IuwGbZbJ3zSYCDzs1Q6OhcneHOO+0NzrCWAT4lcUvpL/Nm343yrf9e//QQyc+YqIY9Llb7fyfAijRe3Nd9ssUpZv1/twwPXe4zY0JbtBbwV7aPC3Mzl4f7s3u83c23Ad9nxflm4Yz6xSH8hxgM4Q0wkQ=" Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=debug msg="completed challenge" Jan 13 22:16:42 volumio go-librespot[7425]: time="2025-01-13T22:16:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:43 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:43 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 13 22:16:43 volumio volumio[816]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 13 22:16:43 volumio volumio[816]: info: Received Get System Version Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 13 22:16:43 volumio volumio[816]: info: Received Get System Info Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:43 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:43 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:46 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:46 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 220. Jan 13 22:16:46 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:46 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:46 volumio go-librespot[7447]: Librespot-go daemon starting... Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=info msg="generated new device id: 649fd867b120976d4ee70b81c47f806b704a9da3" Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=debug msg="obtained new client token: AADdkUfOHHuTGaCYT6Et/rZrMIODGsi5tKW+zlwvhSVn4kLw4tutvFcH0XbaKeocIKQAIOQmXzD20HVc0UcDm2wFtb3u4p+YVPz0jY2iVmZhC3/VABVSHpOFSmQR+DWt7aUYcozo9j13T0Z8iZ9iYLXdw7RhrvrBKahsSWYTzVweEp93sfIvCe9V8siLLtwH22g8PHwbe990Y3Lco0KalNEO74Z6uhC+gV5Wt9LpB3QVagl18IhqJ7IUa4I=" Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=debug msg="completed challenge" Jan 13 22:16:46 volumio go-librespot[7447]: time="2025-01-13T22:16:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:47 volumio volumio[816]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Jan 13 22:16:47 volumio sudo[7461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 13 22:16:47 volumio sudo[7461]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:47 volumio sudo[7461]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:47 volumio volumio[816]: info: MPD Permissions set Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio sudo[7465]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 13 22:16:47 volumio sudo[7465]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:47 volumio systemd[1]: Stopping Music Player Daemon... Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 13 22:16:47 volumio systemd[1]: mpd.service: Succeeded. Jan 13 22:16:47 volumio systemd[1]: Stopped Music Player Daemon. Jan 13 22:16:47 volumio systemd[1]: Starting Music Player Daemon... Jan 13 22:16:47 volumio sudo[7473]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 13 22:16:47 volumio sudo[7473]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:16:47 volumio sudo[7473]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:47 volumio mpd[7475]: Jan 13 22:16 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 13 22:16:47 volumio systemd[1]: Started Music Player Daemon. Jan 13 22:16:47 volumio sudo[7465]: pam_unix(sudo:session): session closed for user root Jan 13 22:16:47 volumio volumio[816]: error: updateQueue error: null Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 13 22:16:47 volumio volumio[816]: info: Discovery: Getting this device information Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::volumioGetState Jan 13 22:16:47 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 13 22:16:49 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:49 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221. Jan 13 22:16:50 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:50 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:50 volumio go-librespot[7479]: Librespot-go daemon starting... Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=info msg="generated new device id: 3cd69617eb3e16be8f86bb9b2ff6d696488a8848" Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=debug msg="obtained new client token: AABCRb8snxsS/svimt+JOjvFbD8x8AjoSbCciRZNPo/M2qHiHNlZsQ/EjbEfZ+MtJB6V4Ge2kUtbJL5SvXxmS8m228Z49ZxUyT45YRbRbpA+3jilLgGzZV4fm8JMweUZermUvlcXJUWIj7ZNSRfVzFjbDaZ5sNQp+j2oXI1sAWvz91y+f7RPfHqwMgT0YuwnFwh/YaMOqb38jU4KtJ65j5YSzNkixj7stmy73S0JOnEv6J1MTx7DJYaF5AI=" Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=debug msg="completed challenge" Jan 13 22:16:50 volumio go-librespot[7479]: time="2025-01-13T22:16:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:52 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:52 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222. Jan 13 22:16:54 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:54 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:54 volumio go-librespot[7488]: Librespot-go daemon starting... Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=info msg="generated new device id: 22db993d9220f927a21ad9b6a02e50d131260466" Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=debug msg="obtained new client token: AAAKg9PQ0LoWlvJl1Jqle4N91Aa3xHRTP+JqcC3xRr610V8r+Fsa94XbD4tyUNrPQ/FR4L5+7L1RJ1AO60skM8TyRYVOI9EBAo6CXxnAWP5qivMr7AnEt+gtuICXkRqTDdzh580oiUj1j6aj9Q0pYTLlWRFrNq59zvD09sUB7I472iUQBOBm55uoZhEPUMpVccnzv7ktZ2Lyd6TCWOgGX2EVs9KXCEa+jvr5xR+BPUkEsgr27tcJzDKPGBU=" Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=debug msg="completed challenge" Jan 13 22:16:54 volumio go-librespot[7488]: time="2025-01-13T22:16:54+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:16:55 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:55 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:58 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:16:58 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:16:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:16:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223. Jan 13 22:16:58 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:16:58 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:16:58 volumio go-librespot[7513]: Librespot-go daemon starting... Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=info msg="generated new device id: 95d3d2a3e7df642e862bddbbe19aa84259aaa2e2" Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=debug msg="obtained new client token: AAD/VRRqiVCwOTSXMxOW5cOUAEEdY7AsrQ0jjE2lG8i0xV+N21DnkhbdR6CE+H331apxAdeo5a0QrCT7WsgfraX4cHCXLT93GGla+Tl2amT00QDigywYmEQbDirGISX0DEkd3WXZMpyj8yy1Ifc9jarFwsiiQQpzj0VbQy9U/DckHMpoxIxwAwKGfe04R1Xyu83UMNAUlnInsC3/eMLtnmDR0nwlmLtEY8BzmeAezGHLBhxrsDmJXtKHpDM=" Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=debug msg="completed keyexchange" Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=debug msg="completed challenge" Jan 13 22:16:58 volumio go-librespot[7513]: time="2025-01-13T22:16:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:16:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:16:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:17:01 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:17:01 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:17:01 volumio volumio[816]: info: Retrieving Cloud Streaming UI Jan 13 22:17:01 volumio volumio[816]: info: Getting Tidal Cloud Configuration Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:17:01 volumio volumio[816]: info: Getting Qobuz Cloud Configuration Jan 13 22:17:01 volumio volumio[816]: info: Asking plugin for UI Config Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:17:01 volumio volumio[816]: info: Getting Spotify Cloud Configuration Jan 13 22:17:01 volumio volumio[816]: info: Asking plugin for UI Config Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:17:01 volumio volumio[816]: info: Saving Spotify Acccount Jan 13 22:17:01 volumio volumio[816]: info: Got Tidal Cloud Configuration Jan 13 22:17:01 volumio volumio[816]: info: Got it Jan 13 22:17:01 volumio volumio[816]: info: Got it Jan 13 22:17:01 volumio volumio[816]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 13 22:17:01 volumio volumio[816]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::volumioGetBrowseSources Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::volumioGetBrowseSources Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::volumioGetBrowseSources Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 13 22:17:01 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 13 22:17:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:17:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 224. Jan 13 22:17:02 volumio systemd[1]: Starting Cleanup of Temporary Directories... Jan 13 22:17:02 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:17:02 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:17:02 volumio go-librespot[7522]: Librespot-go daemon starting... Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=info msg="generated new device id: d709fec565a5d22084b4b57f04837acee16163ea" Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:17:02 volumio systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Jan 13 22:17:02 volumio systemd[1]: Started Cleanup of Temporary Directories. Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=debug msg="obtained new client token: AAD7X63IrCXH0qmshf+nJ3MV9lulsyjw+R3aFYRTnsr7U4/R2f4TThK3hqdsJVBIBSywUUSEOi1QwfZdqF/OF/zHkXAQe0XrflNpDiV83qUTW7mCtUzl97AmCgosH0bDLkXY4jeH7eelqa6XzzcuGxsCPJRi7BCELkAJUFHvdvT34Lj5+kg984BijcrP1WHjO5usV9MGeXXlUwToB5vLKszcAkLgGoRz0mp1/2B8GkV9NxCFW3xZJS5Q1FQ=" Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=debug msg="completed keyexchange" Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=debug msg="completed challenge" Jan 13 22:17:02 volumio go-librespot[7522]: time="2025-01-13T22:17:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 13 22:17:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 13 22:17:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 13 22:17:04 volumio volumio[816]: info: Initializing connection to go-librespot Websocket Jan 13 22:17:04 volumio volumio[816]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 13 22:17:04 volumio volumio[816]: info: Disabling MyMusic plugin upnp Jan 13 22:17:04 volumio sudo[7546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jan 13 22:17:04 volumio sudo[7546]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 13 22:17:04 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Jan 13 22:17:04 volumio volumio[816]: error: Upnp client error: Error: This socket has been ended by the other party Jan 13 22:17:05 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 13 22:17:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 13 22:17:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 225. Jan 13 22:17:06 volumio systemd[1]: Stopped go-librespot Daemon. Jan 13 22:17:06 volumio systemd[1]: Started go-librespot Daemon. Jan 13 22:17:06 volumio go-librespot[7548]: Librespot-go daemon starting... Jan 13 22:17:06 volumio go-librespot[7548]: time="2025-01-13T22:17:06+01:00" level=info msg="generated new device id: 8254b93580355e4699abfbb0f92f5e639d3fefba" Jan 13 22:17:06 volumio go-librespot[7548]: time="2025-01-13T22:17:06+01:00" level=debug msg="stored credentials found for sloam8" Jan 13 22:17:06 volumio volumio[816]: info: Enabling MyMusic plugin upnp Jan 13 22:17:06 volumio volumio[816]: info: Enabling plugin upnp Jan 13 22:17:06 volumio volumio[816]: info: Loading plugin "upnp"... Jan 13 22:17:06 volumio volumio[816]: info: [1736803026199] Starting Upmpd Daemon Jan 13 22:17:06 volumio volumio[816]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 13 22:17:06 volumio volumio[816]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 22:17:06 volumio volumio[816]: Error: listen EADDRINUSE: address already in use :::6599 Jan 13 22:17:06 volumio volumio[816]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jan 13 22:17:06 volumio volumio[816]: at listenInCluster (net.js:1379:12) Jan 13 22:17:06 volumio volumio[816]: at Server.listen (net.js:1465:7) Jan 13 22:17:06 volumio volumio[816]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jan 13 22:17:06 volumio volumio[816]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jan 13 22:17:06 volumio volumio[816]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jan 13 22:17:06 volumio volumio[816]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 13 22:17:06 volumio volumio[816]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jan 13 22:17:06 volumio volumio[816]: code: 'EADDRINUSE', Jan 13 22:17:06 volumio volumio[816]: errno: -98, Jan 13 22:17:06 volumio volumio[816]: syscall: 'listen', Jan 13 22:17:06 volumio volumio[816]: address: '::', Jan 13 22:17:06 volumio volumio[816]: port: 6599 Jan 13 22:17:06 volumio volumio[816]: } Jan 13 22:17:06 volumio volumio[816]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 13 22:17:06 volumio go-librespot[7548]: time="2025-01-13T22:17:06+01:00" level=debug msg="obtained new client token: AABnjCCtJcyW8IWv+OPT+4xhHQBS5YzO3dvGGV75RPW2P/IiM8rpK+upuv6OO3QRNTqxg9/wRhZkJ85D2gFcIOjYfRs6hZuHzDEd0IKmm1jz7aPoTuz4V5ehulnqrwaEYTCjr9kR4+uWrF2SVt1yKoDlSHjyk5f7MrM5NuGd8YAnUefkigJq9fAI4ctVNvEq2UGC+tZBIB6v8EFhO+PU80D9qPPrl/IPM7ZQaNk3gUfv6OigZGDTbejm3tg=" Jan 13 22:17:06 volumio sudo[7566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-13 22:16 Jan 13 22:17:06 volumio sudo[7566]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"