-- Logs begin at Mon 2024-10-28 04:26:43 CET, end at Mon 2024-10-28 06:41:57 CET. -- Oct 28 06:40:00 volumio-chambre go-librespot[20594]: time="2024-10-28T06:40:00+01:00" level=debug msg="completed challenge" Oct 28 06:40:00 volumio-chambre go-librespot[20594]: time="2024-10-28T06:40:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:00 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:02 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:02 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:03 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:03 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:03 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:03 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9796. Oct 28 06:40:03 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:03 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:03 volumio-chambre go-librespot[20602]: Librespot-go daemon starting... Oct 28 06:40:03 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:03+01:00" level=info msg="generated new device id: d37369a019c024c1903c8e040e70d4949fe81b11" Oct 28 06:40:03 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:03+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:03 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:03+01:00" level=debug msg="obtained new client token: AAAaaSbI+Ee9wqjuVrJqQJYvDdFWGapLJAIxR/l+ekMbh8tEsXdyFq1PY3A8egVVa/gGfoO4OsumAJ75GqDGfdTPYRe6qUsN0t3yW0zjLEXn4FhyAFjZVgbw90qam3/Bv7uPCeF6bvCbZSQMKy2ag2UmKQxeK5tZi7ZhF+whGx4nX738pfuqZpk9dRwCbwVySKeAFw4IcWlV12biMxVCVYk11ZMnuvFEK5C6ZABCo8+5MCMCRHqgIW0ryPIvKw==" Oct 28 06:40:03 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:03+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]" Oct 28 06:40:03 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:03+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:04 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:04+01:00" level=debug msg="completed challenge" Oct 28 06:40:04 volumio-chambre go-librespot[20602]: time="2024-10-28T06:40:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:04 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:05 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:05 volumio-chambre volumio[1060]: info: [1730094005800] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:05 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:05 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:06 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:06 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:07 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:07 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9797. Oct 28 06:40:07 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:07 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:07 volumio-chambre go-librespot[20610]: Librespot-go daemon starting... Oct 28 06:40:07 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:07+01:00" level=info msg="generated new device id: ec12850d51859e1f8783920c73f6783d15a87586" Oct 28 06:40:07 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:07+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:07 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:07+01:00" level=debug msg="obtained new client token: AABbcSmYCliUkktlrd358ZE3o6TGY6I5rTdDIip87/hsXu6OX13pLdDg4cRyGz4SSM1auRw1pcboSFnAy14PRMLtEY7AKjM0RqFNUGmBVi2h2koBnx/krp//w7NzlXSmb0/BngoxrN90CofxnivmICVnwedsoPizCuit7uMMZcE5hOFtZBU5KLEfcY8WM9lOi1PvJVbFpbSaZC8JatBWgDAsvQUKbxSj1pTzNeDa6el/e8+/tYdpeYyaAtUFOg==" Oct 28 06:40:07 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:07+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]" Oct 28 06:40:07 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:07+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:08 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:08+01:00" level=debug msg="completed challenge" Oct 28 06:40:08 volumio-chambre go-librespot[20610]: time="2024-10-28T06:40:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:08 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:08 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:08 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:08 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:10 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:10 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:11 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:11 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:11 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:11 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9798. Oct 28 06:40:11 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:11 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:11 volumio-chambre go-librespot[20618]: Librespot-go daemon starting... Oct 28 06:40:11 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:11+01:00" level=info msg="generated new device id: a25049c4b3854ba992891104ae837422f0e08f89" Oct 28 06:40:11 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:11+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:11 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:11+01:00" level=debug msg="obtained new client token: AACVJbUbhKwoBJPG1lv3nky4pkshLb8uGKTuUw774x+rQWNfwKHH6WAr9+l09XUXvYix2oSGaP5E4jfbewCE6gVTWcFHhQs/ADAoFJ8NxZHrwqT1OnijwaHX/Fwh0BqgqdHbeFf+r9uCmXu9XtxrTJwCQaKa2lySRwsPHcJLlVc3M7tq8+9ZdkLLV1TbnaEQsgDznFSObqJvvlF4zGj8DGnKsn1HDz0VAgKJLgBQsgCkJ/uMxNLrKR/cEfCFFA==" Oct 28 06:40:11 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:11+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]" Oct 28 06:40:11 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:11+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:12 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:12+01:00" level=debug msg="completed challenge" Oct 28 06:40:12 volumio-chambre go-librespot[20618]: time="2024-10-28T06:40:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:12 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:12 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioGetVisibleSources Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 06:40:14 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 28 06:40:14 volumio-chambre volumio[1060]: info: [1730094014098] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:14 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:14 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:15 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:15 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:15 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:15 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9799. Oct 28 06:40:15 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:15 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:15 volumio-chambre go-librespot[20627]: Librespot-go daemon starting... Oct 28 06:40:15 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:15+01:00" level=info msg="generated new device id: fe348ca574afac124b3662d60dae68ae4ba35ee3" Oct 28 06:40:15 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:15+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:15 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:15+01:00" level=debug msg="obtained new client token: AAAa0SORCywCW1DGqntYL9VU2X+VsmFt0AsY77nZoYzbkYLulgDzUm7XihEPvRKy+KQvQhkU2BJqim8wxaP3Wr4443AIuH6OTLLxlQmgCOj7OQ9BM6XYaaVyS7nL/9ZadQT9m5r4lZ1T50EP7mZ1aX4ZCpEcIXQljAPhnUtkxVrjlucfc5DxkENzYEX2hgRTIJpX8no68pgfISQyuFPsf46nkkoVNHLCLBkuv/7FTUSDVeJA3u0LN0+sN+qy7g==" Oct 28 06:40:15 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:15+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]" Oct 28 06:40:15 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:15+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:16 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:16+01:00" level=debug msg="completed challenge" Oct 28 06:40:16 volumio-chambre go-librespot[20627]: time="2024-10-28T06:40:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:16 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:16 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioGetVisibleSources Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 06:40:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 28 06:40:17 volumio-chambre volumio[1060]: info: [1730094017702] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:17 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:17 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:18 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:18 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9800. Oct 28 06:40:19 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:19 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:19 volumio-chambre go-librespot[20635]: Librespot-go daemon starting... Oct 28 06:40:19 volumio-chambre go-librespot[20635]: time="2024-10-28T06:40:19+01:00" level=info msg="generated new device id: 16ed399e596c67fb13a6ee7e707b6420f13d8fd3" Oct 28 06:40:19 volumio-chambre go-librespot[20635]: time="2024-10-28T06:40:19+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:19 volumio-chambre go-librespot[20635]: time="2024-10-28T06:40:19+01:00" level=debug msg="obtained new client token: AADysp2s4ALyxGovTTrgxycul+JHHBiwvxlpZ8HgGDhJZjUWQVFLEJaXLrhXuTOqzEHrFaAhfY5S8m514Ggf5Crfz4m1l/ZEt++YqG5MHoB8ifE61/ViHGRhREkv5760m0mHls0oxm6LKJISE8JwKK672R1+zi6R/K0xL7UdMfy16SYVgmcdDY9W8laFyBG+ToFObJWFGCQUsuQG/14pAXmh0J45jM6gMs+J2RQk6ZN0jq6aZ8QRT/+FkChrmA==" Oct 28 06:40:19 volumio-chambre go-librespot[20635]: time="2024-10-28T06:40:19+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]" Oct 28 06:40:19 volumio-chambre go-librespot[20635]: time="2024-10-28T06:40:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Oct 28 06:40:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 6 Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 6 Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:20 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 6 Oct 28 06:40:20 volumio-chambre volumio[1060]: info: [1730094020268] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:20 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:20 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:22 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:22 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:22 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:22 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9801. Oct 28 06:40:22 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:22 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:22 volumio-chambre go-librespot[20644]: Librespot-go daemon starting... Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=info msg="generated new device id: 976b18a4872dce9704b8066c6c8f8072a441c8e1" Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=debug msg="obtained new client token: AADnyEsGXvZOPvwzvwqvZtbtJhSlGNHTtMAT+p4awgg1jOStRMJ+sydwKK3poyw77KE4BMkxEgf3q4I4QElkpju9VYy5kIXXC/rd0jYTUgZND0EV9WkZarO+KocF3kymDsX93nDNR1lsDjNIBndocQkptpiqPG8D9kRLGZdpKF6Zg1Gz6knIeTvQyUzldADZIvf5EvdgomkufHWApF35uXXTYfF1cj28Qif8Md9ReXxn8fQI8XGsdZc6VVA=" Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+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]" Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=debug msg="new websocket client" Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Connection to go-librespot Websocket established Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:23 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:23 volumio-chambre volumio[1060]: info: [1730094023679] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=debug msg="completed challenge" Oct 28 06:40:23 volumio-chambre go-librespot[20644]: time="2024-10-28T06:40:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:23 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Oct 28 06:40:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:23 volumio-chambre volumio[1060]: info: Connection to go-librespot Websocket closed Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:25 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:25 volumio-chambre volumio[1060]: info: [1730094025709] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:25 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:25 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:26 volumio-chambre volumio[1060]: info: Getting Spotify volume Oct 28 06:40:26 volumio-chambre volumio[1060]: (node:1060) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:26 volumio-chambre volumio[1060]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 28 06:40:26 volumio-chambre volumio[1060]: (node:1060) 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: 883) Oct 28 06:40:26 volumio-chambre volumio[1060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 28 06:40:26 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioGetState Oct 28 06:40:26 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:26 volumio-chambre volumio[1060]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Oct 28 06:40:26 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:26 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:26 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:26 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9802. Oct 28 06:40:26 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:26 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:26 volumio-chambre go-librespot[20653]: Librespot-go daemon starting... Oct 28 06:40:26 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:26+01:00" level=info msg="generated new device id: 888a054d48b6d99a792c9f4f5c8a038d6dcb069f" Oct 28 06:40:26 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:26+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:27 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:27 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:27+01:00" level=debug msg="obtained new client token: AAA6Dyavntv4EuuuX4uoE1XrW6iH3v3uIGX/OOZJr89xiY4rL1XOJvx+3s2f1kqki1vuFymIc4ultYuhsDP3LfPn670bL7U/LPkiO0mGkRnY8XkBRCLwU1s3MVEam5A992cp0ig1S3SwPfnlutzAr53hpfkji7klqvPcqoyZxam1EN9TgN1rpiXtQrKaQHLMy2KbqK3C+Ri1YOaIcyWZ/LXpX1Qo7oKoCzPyLkh4Ogu18GEnh/s54mrKexU=" Oct 28 06:40:27 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:27+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]" Oct 28 06:40:27 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:27 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:27+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:27 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:27+01:00" level=debug msg="completed challenge" Oct 28 06:40:27 volumio-chambre go-librespot[20653]: time="2024-10-28T06:40:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:29 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:29 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:30 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:30 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9803. Oct 28 06:40:30 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:30 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:30 volumio-chambre go-librespot[20661]: Librespot-go daemon starting... Oct 28 06:40:30 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:30+01:00" level=info msg="generated new device id: 59d9af66c2b1f7b0f543d1b28ad97e7b8bd763f0" Oct 28 06:40:30 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:30+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:31 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:31+01:00" level=debug msg="obtained new client token: AACD2GgXHuVDdCkyxDNY20a15Q8L74/Cp3WuXGb2JR7GYzoD+aDvZaUlpx/sl+U25TcBjUbo83QmT1AaIHpbyzfmUkyId2kXuTo5nyB29KbRs2CUuKzrPhocpKRMlaS6qTocJL+6hPZ1ETPY/zqZt0nXJlc/FemgKOQFzqAUWQG4lUWb3tkiYYJlbRszbGhwuEkJZgmNKZft8YfmZMLZOih80tGhinwsmKTn9fPIMMsdYisGRoMhf2OQxvI=" Oct 28 06:40:31 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:31+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]" Oct 28 06:40:31 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:31+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:31 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:31+01:00" level=debug msg="completed challenge" Oct 28 06:40:31 volumio-chambre go-librespot[20661]: time="2024-10-28T06:40:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:31 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:31 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:32 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:32 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:32 volumio-chambre volumiologrotate[636]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 28 06:40:32 volumio-chambre volumiologrotate[636]: ls: cannot access 'CHAMBRE': No such file or directory Oct 28 06:40:34 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:34 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9804. Oct 28 06:40:34 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:34 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:34 volumio-chambre go-librespot[20711]: Librespot-go daemon starting... Oct 28 06:40:34 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:34+01:00" level=info msg="generated new device id: fe0b9cb7053a01fe29b81eff1c1967a3a7b45d72" Oct 28 06:40:34 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:34+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:35 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:35+01:00" level=debug msg="obtained new client token: AACxcIMjHkg95ZnO0kZ7mSxyBHsypQ8d+ItL/zIUkhG8FMVP5Y1bkaQEqR7QSzx1iMBwMWkF3mfBA7Xq+9Jm9AtKQTfTsPVQxonGNW29Cc+QIrankfGInmAf/F3um3v3kq2QZiblVM6bk+DO9iZ88pr/bRA+4oAwbErCQEWcWf2B2Iuh0KfNSZ/hUUtU+yIYmtSJK1aV3CiuBsNUfcuBkqJH7eteWdd/KCKxR5TgDpusiNCeo6e2/7/pub0=" Oct 28 06:40:35 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:35+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]" Oct 28 06:40:35 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:35+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:35 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:35 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:35 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:35+01:00" level=debug msg="completed challenge" Oct 28 06:40:35 volumio-chambre go-librespot[20711]: time="2024-10-28T06:40:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:35 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:35 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:38 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:38 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:38 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:38 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9805. Oct 28 06:40:38 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:38 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:38 volumio-chambre go-librespot[20721]: Librespot-go daemon starting... Oct 28 06:40:38 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:38+01:00" level=info msg="generated new device id: 945c31f4e47c65ada90cc9636352ee06c946a516" Oct 28 06:40:38 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:38+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:39 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:39+01:00" level=debug msg="obtained new client token: AABe0Q7m25ZbqfFxbPhtO0pJJdzhEVLkd+DFCUHu2HOv6vI4jUAx5eyEQMfgQt60w4c16SpxgQ9dFPi/c0VEsI/BMh6DbqyegKbnO9PMDWmr4VY67YGXECEisNqw5ypNKmfOUUQlf4B9EQKcI5s7CTfU694+/PArnnP9uCyc6dBOSo6DejMy5hTcGfXohWxGFa+s9N8dxkJtAo17ePrZPWECVvTi7UThGVpMMGXGAgW+LotW0PUu11wIlFE=" Oct 28 06:40:39 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:39+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]" Oct 28 06:40:39 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:39+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:39 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:39+01:00" level=debug msg="completed challenge" Oct 28 06:40:39 volumio-chambre go-librespot[20721]: time="2024-10-28T06:40:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:40 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:40 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:41 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:41 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:42 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:42 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9806. Oct 28 06:40:42 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:42 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:42 volumio-chambre go-librespot[20731]: Librespot-go daemon starting... Oct 28 06:40:42 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:42+01:00" level=info msg="generated new device id: 939d28e70ac494232f38ec940175829f765a76a8" Oct 28 06:40:42 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:42+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:43 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:43 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:43 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:43+01:00" level=debug msg="obtained new client token: AACfXF37APi2xddT/VEy1xr3rCPhf3ZT+xGCgOH2yvmeNJ2uBxOBqQ18Vd4+of2e6h9+sLhfesShnCGQ0wdn8MjugCdrRLy5EaG1a4HTPWrhea4tWZYuTpsgClgSM6sUC/qnErFRsWl6sV1LehTkSt5KB3/EceMkBz0qqOWdra1eA5o607KWwg5tfjIVsHNHsBC7irhUODQH57nxauuoy7LQx7AiB5IICZGkmags8VTjO+/uW7H3AYhYHyA=" Oct 28 06:40:43 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:43+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]" Oct 28 06:40:43 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:43+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:43 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:43+01:00" level=debug msg="completed challenge" Oct 28 06:40:43 volumio-chambre go-librespot[20731]: time="2024-10-28T06:40:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:44 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:44 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:45 volumio-chambre volumio[1060]: Searching all installed plugins Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: spop , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: tidal , search Oct 28 06:40:45 volumio-chambre volumio[1060]: info: searchTIDALUri took 262 milliseconds Oct 28 06:40:45 volumio-chambre volumio[1060]: info: search took 262 milliseconds Oct 28 06:40:46 volumio-chambre volumio[1060]: info: searchQOBUZUri took 725 milliseconds Oct 28 06:40:46 volumio-chambre volumio[1060]: info: All search sources collected, pushing search results Oct 28 06:40:46 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:46 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9807. Oct 28 06:40:46 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:46 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:46 volumio-chambre go-librespot[20739]: Librespot-go daemon starting... Oct 28 06:40:46 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:46+01:00" level=info msg="generated new device id: 64ba03e28ce1233eee1b7ee2244b7b0de63d5143" Oct 28 06:40:46 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:46+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:47 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:47+01:00" level=debug msg="obtained new client token: AAB4b8qwIDWeXBnC0q52816L1b7lWFgmE2VCjswubUp57X1owuPtW6KiFyOzOYe8tkxDLZccjKcAKNuBiNTc4j7b0KUIwnrvyUJ3W8ZAh0ttDdIZFCkh6BRscxpeAeR5QX/y4nPsWmAjYhMufraMImoxgbFk3ga6z0lgjVhQ50O23rw+iDTt54tAkXLc3PCp3/pqxAQvnNUtUZ9b9gRiYjOl8a9fDvr3f92m8K+UQw36piZSUuA3SuKdyFQ=" Oct 28 06:40:47 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:47+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]" Oct 28 06:40:47 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:47+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:47 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:47+01:00" level=debug msg="completed challenge" Oct 28 06:40:47 volumio-chambre go-librespot[20739]: time="2024-10-28T06:40:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:47 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:47 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:48 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:48 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:48 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 28 06:40:48 volumio-chambre volumio[1060]: info: In handleBrowseUri, curUri=spotify:artist:5resnspF60fUdkKmQHn8em Oct 28 06:40:48 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:48 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:48 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:48 volumio-chambre volumio[1060]: info: Executing endpoint getSimilarArtists Oct 28 06:40:48 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Oct 28 06:40:48 volumio-chambre volumio[1060]: info: Executing endpoint metavolumio Oct 28 06:40:48 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 28 06:40:50 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:50 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:50 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:50 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9808. Oct 28 06:40:50 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:50 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:50 volumio-chambre go-librespot[20748]: Librespot-go daemon starting... Oct 28 06:40:50 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:50+01:00" level=info msg="generated new device id: 8ac8c481d9fa25a8747a98f0549d3e60b7e9be26" Oct 28 06:40:50 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:50+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:51 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:51+01:00" level=debug msg="obtained new client token: AADqLx7tkhikxRfwkbyhp0qhfP6Zybi1CKojulRU/8pokJhNr05EbSWqXMF+rGW5d14jhejJbHQtd8UnYQZet+bhQO/ouyDOPvzGeDZCKapaFcEEdIhxa5cWsk2xQVcRaoyy+kkazAfrNrm9R+u1zvIopMtu6hXFUJnRunbInnkkA3VFgyTjbHOQkI0xtia7xKuqPVKUPfORGhBpvBcVFcGxsrJ/IMy3WMRFs+Al3L3lWBprwGyOSJ+Lz5I=" Oct 28 06:40:51 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:51+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]" Oct 28 06:40:51 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:51+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:51 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:51+01:00" level=debug msg="completed challenge" Oct 28 06:40:51 volumio-chambre go-librespot[20748]: time="2024-10-28T06:40:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7mRYAphmzBkGqE82Q196Ip Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:41GEAHVr5DdxEBHTXAYaJh Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4lDU1zEZnIgQz4A5R9PWS8 Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:3z7EsXU4kC7xvwTqNVTmZG Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4U6SsSNef5oAGA0eMfvMDR Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:4B5FArULKY7y4WAEkW7exT Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:2QXECI687bHJoQiunJBBLj Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:6051Cr1ieO10nTt9rONI6c Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:0nHu17Gq9ANfsZRO362YCi Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Adding Item to queue: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Using cached record of: spotify:track:7ib2PxnOEbqOc1GQYFSoBD Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:40:52 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:40:52 volumio-chambre volumio[1060]: info: [1730094052699] ControllerSpotify::clearAddPlayTrack Oct 28 06:40:52 volumio-chambre volumio[1060]: info: Sending Spotify command with payload to local API: /player/play Oct 28 06:40:52 volumio-chambre volumio[1060]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:52 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:52 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:53 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:53 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:54 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:54 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9809. Oct 28 06:40:54 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:54 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:54 volumio-chambre go-librespot[20757]: Librespot-go daemon starting... Oct 28 06:40:54 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:54+01:00" level=info msg="generated new device id: 35231fdca6224ccc10c78a358b8ed530b9b6044f" Oct 28 06:40:54 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:54+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:55 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:55+01:00" level=debug msg="obtained new client token: AABqRrXV5eMAysfomBBzQQAuZJRFMjLAksMj1Qo9Hpk3mqadsfGMKOSzQ0CK59Lxuhizn7vHTJjfilc4rNY/MXe2auuDWwPVO5fgKGL3Wh5IwHurrR70oNN0eGGsJg9H5PhEbgjQ8H+IZJzTTZY4LSMWokERmJQpJpPuqfmfSQwGb1nNfgywTlSTvkeOIZjQeoPwHISyChmeZDeT0nEhaOKCP0h4hRVfQPt3eEj6cwR4m55QczcC0d5drNg=" Oct 28 06:40:55 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:55+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]" Oct 28 06:40:55 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:55+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:55 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:55+01:00" level=debug msg="completed challenge" Oct 28 06:40:55 volumio-chambre go-librespot[20757]: time="2024-10-28T06:40:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:55 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:55 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:56 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:56 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:40:56 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:56 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:58 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:40:58 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9810. Oct 28 06:40:58 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:40:58 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:40:58 volumio-chambre go-librespot[20767]: Librespot-go daemon starting... Oct 28 06:40:58 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:58+01:00" level=info msg="generated new device id: 3eae530791fcf479c3ccd63ace973ae6fbb28658" Oct 28 06:40:58 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:58+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:40:59 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:59+01:00" level=debug msg="obtained new client token: AAAWDBpCZ5N6vLay3vDFa4XH5KHxMpawgHZzVxHI3Qs6QSAhxv24UXN3UcCAP16UIiMAE6OMFiqWyTwWs7vzmvZzZiTEIP/MOv3XYYMnEO9v9OkljU3zw0f5Nle2jQlQ5xM2XcJY0kP1anIGX8Zm3BgZsyBEaRPTiotB4e1jc5cqMmPsUcg70+9inx/XzovWr21y7p99Sl8GvuClrNfVjZFquyn4gHqsLy0GRxL8HnfTa/BNFop/6khF2b4=" Oct 28 06:40:59 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:59+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]" Oct 28 06:40:59 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:59+01:00" level=debug msg="completed keyexchange" Oct 28 06:40:59 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:59+01:00" level=debug msg="completed challenge" Oct 28 06:40:59 volumio-chambre go-librespot[20767]: time="2024-10-28T06:40:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:40:59 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:40:59 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:40:59 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:40:59 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:40:59 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 28 06:41:00 volumio-chambre volumio[1060]: info: handleBrowseUri took 86 milliseconds Oct 28 06:41:00 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:41:00 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:41:00 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:00 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:02 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:02 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:02 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9811. Oct 28 06:41:02 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:02 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:02 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:02 volumio-chambre go-librespot[20775]: Librespot-go daemon starting... Oct 28 06:41:02 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:02+01:00" level=info msg="generated new device id: e21cc789acd5721265452584b9ff3feae2de33e3" Oct 28 06:41:02 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:02+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:03 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:03+01:00" level=debug msg="obtained new client token: AACOZltFSyC6pq7qOXbX4NVUWuk+LXbx2m35S4mhIu6qdIZkzjOyR3UKniQjBYyHUshdUjqZVW5OJYKRWR8wClW+E/p1viO/51nP8gVRO2si1XM+gPUuayjvsHe2ybDTBNr8YkQx87vsMs0j+0aQEq4csviF/kxQbVgpWuMirN/gqv/a9wSNqKCjLB/4ulML5/cp6enTAGddSZwCpnfqchhjBQdtLj/rx9kGmtHri8Y87oVf7OsNLEpGUWs=" Oct 28 06:41:03 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:03+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]" Oct 28 06:41:03 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:03+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:03 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:03+01:00" level=debug msg="completed challenge" Oct 28 06:41:03 volumio-chambre go-librespot[20775]: time="2024-10-28T06:41:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:03 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:03 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:04 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:04 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:05 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:05 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:06 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:06 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9812. Oct 28 06:41:06 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:06 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:06 volumio-chambre go-librespot[20784]: Librespot-go daemon starting... Oct 28 06:41:06 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41:06+01:00" level=info msg="generated new device id: 0544cc68b010b9d1d05b958838c43eeeed555c0a" Oct 28 06:41:06 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41:06+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:07 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41:07+01:00" level=debug msg="obtained new client token: AABzUZ225eD106xGmOZ+8LPQQ1JfZnXbFgRaWXrezXvvgtXR4PXcmhH0fOrX70w1WgGkao4T/FaSAbH8ouRDS2TPvVfthhbN6KbVsYnE3w8BVZwEmx8YgzdkYIS7BfdMy4ll3/6n6WWYw8ca4pPkOJfTicO1G0xTSg//Fz8QZr/dnh//+863QBQVLI9ITqI0W3oKUWyr/4c2Cq+YQDrYZlPn7Ul4wyd5n9TaYJGuJpzjlQOAEPRhOt+jZoY=" Oct 28 06:41:07 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41:07+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]" Oct 28 06:41:07 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41:07+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:07 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41:07+01:00" level=debug msg="completed challenge" Oct 28 06:41:07 volumio-chambre go-librespot[20784]: time="2024-10-28T06:41: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" Oct 28 06:41:07 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:07 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:08 volumio-chambre volumio[1060]: Searching plugin music_service/qobuz Oct 28 06:41:08 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 28 06:41:08 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:08 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:09 volumio-chambre volumio[1060]: info: searchQOBUZUri took 634 milliseconds Oct 28 06:41:09 volumio-chambre volumio[1060]: info: All search sources collected, pushing search results Oct 28 06:41:09 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:09 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:10 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:10 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9813. Oct 28 06:41:10 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:10 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:10 volumio-chambre go-librespot[20792]: Librespot-go daemon starting... Oct 28 06:41:10 volumio-chambre go-librespot[20792]: time="2024-10-28T06:41:10+01:00" level=info msg="generated new device id: 7793bd0a75610ccee54aa6a84eda01bb6de5247c" Oct 28 06:41:10 volumio-chambre go-librespot[20792]: time="2024-10-28T06:41:10+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:11 volumio-chambre go-librespot[20792]: time="2024-10-28T06:41:11+01:00" level=debug msg="obtained new client token: AACb6jbG3hWxJsjO60htHNQiQgmppmd7IOcgszGbmTMiXkZSWmRvd6/4RMiq5jTT/TIMqICM7uXItfRW84y2nYSGJhBkDOD2u58Kvq93b7YZPX3dmMVoJJSZOFkoFJU9UruWga3rgjhvvK6psObKHTuPTi4TGf74XWI1Yo2rnXqiE9WesnU2q/LWp44dX6mB6LNOoSzEeWTnaSebA99mZWwlQABU8Pu0WG8zuFYWzWdv0NBECV7l0Ld89uM=" Oct 28 06:41:11 volumio-chambre go-librespot[20792]: time="2024-10-28T06:41:11+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]" Oct 28 06:41:11 volumio-chambre go-librespot[20792]: time="2024-10-28T06:41:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Oct 28 06:41:11 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:11 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:11 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:11 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:12 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:12 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:14 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:14 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9814. Oct 28 06:41:14 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:14 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:14 volumio-chambre go-librespot[20801]: Librespot-go daemon starting... Oct 28 06:41:14 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:14+01:00" level=info msg="generated new device id: 97a397d6dfb322aa5ba122344bc3e353775a69d7" Oct 28 06:41:14 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:14+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:14 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:14+01:00" level=debug msg="obtained new client token: AAD1j5e4UJ27ZmxHJA+/z/2FfytYjtgVe/tIJstG2wPxp4Lr3v6saSZInrSQsxW6TArrMhnZC4KHY/LIxseB2O+0Ce5dKCD1CN1ORlxl/2rwEkgKUmEzUS4xB5K3RPhIPy5AtuPQMnGX7gpWI3x1km0WfzRnCpg6glxYb/SQQfS6Sd2W2/shsoPhvlWJw7yO9hceXs8qi/69XhS3Tl2JRfFVPOqY9N3SkSk64l6HhOMZdZep7ejl2In9Qmf6Pw==" Oct 28 06:41:14 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41: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-gae2.spotify.com:80]" Oct 28 06:41:14 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:14+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:14 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:14 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:14+01:00" level=debug msg="new websocket client" Oct 28 06:41:14 volumio-chambre volumio[1060]: info: Connection to go-librespot Websocket established Oct 28 06:41:15 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:15+01:00" level=debug msg="completed challenge" Oct 28 06:41:15 volumio-chambre go-librespot[20801]: time="2024-10-28T06:41:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:15 volumio-chambre volumio[1060]: info: Connection to go-librespot Websocket closed Oct 28 06:41:15 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:15 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:15 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 28 06:41:15 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:15 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:16 volumio-chambre volumio[1060]: info: handleBrowseUri took 717 milliseconds Oct 28 06:41:16 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:41:16 volumio-chambre volumio[1060]: info: Executing endpoint getSimilarArtists Oct 28 06:41:16 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Oct 28 06:41:16 volumio-chambre volumio[1060]: info: Executing endpoint metavolumio Oct 28 06:41:16 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 28 06:41:17 volumio-chambre volumio[1060]: info: Getting Spotify volume Oct 28 06:41:17 volumio-chambre volumio[1060]: (node:1060) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:17 volumio-chambre volumio[1060]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 28 06:41:17 volumio-chambre volumio[1060]: (node:1060) 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: 884) Oct 28 06:41:17 volumio-chambre volumio[1060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 28 06:41:17 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioGetState Oct 28 06:41:17 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:41:17 volumio-chambre volumio[1060]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Oct 28 06:41:18 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:18 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:18 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:18 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9815. Oct 28 06:41:18 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:18 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:18 volumio-chambre go-librespot[20810]: Librespot-go daemon starting... Oct 28 06:41:18 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41:18+01:00" level=info msg="generated new device id: d1a279e888175c3866799b1ec1adbfd594fabf5d" Oct 28 06:41:18 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41:18+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:18 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41:18+01:00" level=debug msg="obtained new client token: AAD2FJE6uRHsMuW2Yb9MZNoo3qQ3IH8BNqlWlpJo4uUzsFPZWfzJ7SJMzsUDYHjFqLRLgbyIcuE87hYLp/zIBSq1zS61KQ1Aj9gMFKpaPmHdETztJamYXk1CDgIc5hiWbpQM/AHRxNNn48ClDRolhpxYcbN/yPwiUFyGqDWon/F+e3dflC6d1wx8VC8MI0XyiTs29As81/dEPkn1GoT30ON1Lq3iiwFL0L3DiY8b8c4qw/EGCN5DkS8oaLpHBA==" Oct 28 06:41:18 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 28 06:41:18 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41:18+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:19 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41:19+01:00" level=debug msg="completed challenge" Oct 28 06:41:19 volumio-chambre go-librespot[20810]: time="2024-10-28T06:41:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:19 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:19 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:19 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:21 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:21 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:22 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:22 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9816. Oct 28 06:41:22 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:22 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:22 volumio-chambre go-librespot[20818]: Librespot-go daemon starting... Oct 28 06:41:22 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41:22+01:00" level=info msg="generated new device id: 6866b69baf95700f2c8ac6955c493291a8ff65ae" Oct 28 06:41:22 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41:22+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:22 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41:22+01:00" level=debug msg="obtained new client token: AADZk5+1KOInx6lyx8rV84gStdbUFaWBs2c5EdtBDP0UCsS6e8cUWPWN/EYM9Rs7baIn0sZqfhUMifdo3OKsCo9MAKOIGu1guVk7OoJ/iX5W2+0PlzOATCRrpplRYNHnGmenW+LnPerliL3wGVF89VIMN8rCW5z53ykhn/UEauRGmn/rQ7xqb0o01D5ACCcTmJCQUmV35hSSCnjjHeW2pZhAFEjTS/N/CIHp4pun34HYFu+acK0fSSkcoHa/JQ==" Oct 28 06:41:22 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 28 06:41:22 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41:22+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:23 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:23 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:23 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41:23+01:00" level=debug msg="completed challenge" Oct 28 06:41:23 volumio-chambre go-librespot[20818]: time="2024-10-28T06:41:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:23 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::ClearQueue Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::clearPlayQueue Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::addQueueItems Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::addQueueItems Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Preload queue cleared Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Adding Item to queue: qobuz://album/nrnvir9d378fc Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Exploding uri qobuz://album/nrnvir9d378fc in service qobuz Oct 28 06:41:24 volumio-chambre volumio[1060]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 28 06:41:24 volumio-chambre volumio[1060]: info: explodeUri took 654 milliseconds Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushQueue Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::saveQueue Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::updateTrackBlock Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrackBlock Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPlay Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::play index 0 Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::stop Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::play index undefined Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CoreStateMachine::startPlaybackTimer Oct 28 06:41:24 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:41:24 volumio-chambre volumio[1060]: info: [1730094084993] ControllerQobuz::clearAddPlayTrack Oct 28 06:41:24 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 06:41:24 volumio-chambre volumio[1060]: info: sendMpdCommand stop took 3 milliseconds Oct 28 06:41:24 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Oct 28 06:41:24 volumio-chambre volumio[1060]: ---------------------------- MPD announces system playlist update Oct 28 06:41:24 volumio-chambre volumio[1060]: info: Ignoring MPD Status Update Oct 28 06:41:24 volumio-chambre volumio[1060]: info: sendMpdCommand clear took 1 milliseconds Oct 28 06:41:24 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/212933099" Oct 28 06:41:24 volumio-chambre volumio[1060]: error: updateQueue error: null Oct 28 06:41:24 volumio-chambre volumio[1060]: info: ------------------------------ 2ms Oct 28 06:41:25 volumio-chambre volumio[1060]: STREAMING PROXY: Handling url /?data=qobuz://song/212933099 Oct 28 06:41:25 volumio-chambre volumio[1060]: info: Executing endpoint getStreamUrlqobuz Oct 28 06:41:25 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 28 06:41:25 volumio-chambre volumio[1060]: info: getStreamUrl took 486 milliseconds Oct 28 06:41:25 volumio-chambre volumio[1060]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2888464&eid=212933099&fmt=7&profile=raw&app_id=539451548&cid=2092215&etsp=1730097685&hmac=Dxv3oBDydmWvnY-q6b1tM81ty0g Oct 28 06:41:25 volumio-chambre volumio[1060]: STREAMING PROXY: Response: 200, length: 35261120 Oct 28 06:41:25 volumio-chambre volumio[1060]: STREAMING PROXY: Client dropped request, destroying Oct 28 06:41:25 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/212933099" Oct 28 06:41:25 volumio-chambre volumio[1060]: info: Oct 28 06:41:25 volumio-chambre volumio[1060]: ---------------------------- MPD announces system playlist update Oct 28 06:41:25 volumio-chambre volumio[1060]: info: Ignoring MPD Status Update Oct 28 06:41:25 volumio-chambre volumio[1060]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/212933099" took 1 milliseconds Oct 28 06:41:25 volumio-chambre volumio[1060]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 28 06:41:25 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand play Oct 28 06:41:25 volumio-chambre volumio[1060]: info: ------------------------------ 2ms Oct 28 06:41:25 volumio-chambre volumio[1060]: info: sendMpdCommand play took 1 milliseconds Oct 28 06:41:25 volumio-chambre volumio[1060]: STREAMING PROXY: Handling url /?data=qobuz://song/212933099 Oct 28 06:41:25 volumio-chambre volumio[1060]: info: Executing endpoint getStreamUrlqobuz Oct 28 06:41:25 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 28 06:41:25 volumio-chambre volumio[1060]: info: getStreamUrl took 430 milliseconds Oct 28 06:41:25 volumio-chambre volumio[1060]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2888464&eid=212933099&fmt=7&profile=raw&app_id=539451548&cid=2092215&etsp=1730097685&hmac=Dxv3oBDydmWvnY-q6b1tM81ty0g Oct 28 06:41:26 volumio-chambre volumio[1060]: STREAMING PROXY: Response: 200, length: 35261120 Oct 28 06:41:26 volumio-chambre volumio[1060]: info: Oct 28 06:41:26 volumio-chambre volumio[1060]: ---------------------------- MPD announces state update: player Oct 28 06:41:26 volumio-chambre volumio[1060]: info: ControllerMpd::getState Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand status Oct 28 06:41:26 volumio-chambre volumio[1060]: info: FusionDsp - ---- read samplerate, raw: Oct 28 06:41:26 volumio-chambre volumio[1060]: error: FusionDsp - invalid sample rate Oct 28 06:41:26 volumio-chambre volumio[1060]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 28 06:41:26 volumio-chambre volumio[1060]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 28 06:41:26 volumio-chambre volumio[1060]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 28 06:41:26 volumio-chambre volumio[1060]: info: FusionDsp - Nulleq applied Oct 28 06:41:26 volumio-chambre volumio[1060]: info: Oct 28 06:41:26 volumio-chambre volumio[1060]: ---------------------------- MPD announces state update: player Oct 28 06:41:26 volumio-chambre volumio[1060]: info: sendMpdCommand status took 19 milliseconds Oct 28 06:41:26 volumio-chambre volumio[1060]: info: ControllerMpd::getState Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand status Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::parseState Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 06:41:26 volumio-chambre volumio[1060]: info: sendMpdCommand status took 3 milliseconds Oct 28 06:41:26 volumio-chambre volumio[1060]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::parseState Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::parseTrackInfo Oct 28 06:41:26 volumio-chambre volumio[1060]: info: ControllerMpd::pushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreCommandRouter::servicePushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"212933099","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/212933099","trackType":"qobuz"} Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: CURRENT POSITION 0 Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreStateMachine::syncState stateService play Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreStateMachine::syncState currentStatus stop Oct 28 06:41:26 volumio-chambre volumio[1060]: info: ------------------------------ 27ms Oct 28 06:41:26 volumio-chambre volumio[1060]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: ControllerMpd::parseTrackInfo Oct 28 06:41:26 volumio-chambre volumio[1060]: info: ControllerMpd::pushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreCommandRouter::servicePushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CorePlayQueue::getTrack 0 Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1131,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1238 Kbps","isStreaming":false,"title":"212933099","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/212933099","trackType":"qobuz"} Oct 28 06:41:26 volumio-chambre volumio[1060]: verbose: CURRENT POSITION 0 Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreStateMachine::syncState stateService play Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreStateMachine::syncState currentStatus play Oct 28 06:41:26 volumio-chambre volumio[1060]: info: Received an update from plugin. extracting info from payload Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreStateMachine::pushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: MRS: Pushing multiroomSync output update for this device Oct 28 06:41:26 volumio-chambre volumio[1060]: info: MRS: Pushing multiroomSync output Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreStateMachine::pushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioPushState Oct 28 06:41:26 volumio-chambre volumio[1060]: info: MRS: Pushing multiroomSync output update for this device Oct 28 06:41:26 volumio-chambre volumio[1060]: info: MRS: Pushing multiroomSync output Oct 28 06:41:26 volumio-chambre volumio[1060]: info: ------------------------------ 27ms Oct 28 06:41:26 volumio-chambre volumio[1060]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Oct 28 06:41:26 volumio-chambre volumio[1060]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Oct 28 06:41:26 volumio-chambre volumio[1060]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 28 06:41:26 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:26 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9817. Oct 28 06:41:26 volumio-chambre volumio[1060]: STREAMING PROXY: Client dropped request, destroying Oct 28 06:41:26 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:26 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:26 volumio-chambre go-librespot[20831]: Librespot-go daemon starting... Oct 28 06:41:26 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:26+01:00" level=info msg="generated new device id: 22aa069a0baeea74f164de14cb331801f7fae86b" Oct 28 06:41:26 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:26+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:26 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:26+01:00" level=debug msg="obtained new client token: AABCSujL18oAiApcd4B6R8LJJPw+XgIjk/YB4zZRGnbMSbzoGqrMj3gCcidEliEf8Qu/3IzN56gMmbUSeFP8cy2/kSekehe49LI98h5WOhHWjjORVHA6xxuh9YIc/JUWwdeEPEzwwVPi4neufyV2VixsXau/bq2Ze6N9DGqEM1xaK+LxnnP68ocsXgWfItzLCf+O2tktgEPCu4JrdSjV0R7QZW0WQiVD1lPSYPMvnQD0O7UuWUYH8vsVNMF7fg==" Oct 28 06:41:26 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 28 06:41:26 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:26+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:27 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:27 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:27+01:00" level=debug msg="completed challenge" Oct 28 06:41:27 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:27+01:00" level=debug msg="new websocket client" Oct 28 06:41:27 volumio-chambre volumio[1060]: info: Connection to go-librespot Websocket established Oct 28 06:41:27 volumio-chambre go-librespot[20831]: time="2024-10-28T06:41:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:27 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:27 volumio-chambre volumio[1060]: info: Connection to go-librespot Websocket closed Oct 28 06:41:27 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:27 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:30 volumio-chambre volumio[1060]: info: Getting Spotify volume Oct 28 06:41:30 volumio-chambre volumio[1060]: (node:1060) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:30 volumio-chambre volumio[1060]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Oct 28 06:41:30 volumio-chambre volumio[1060]: (node:1060) 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: 885) Oct 28 06:41:30 volumio-chambre volumio[1060]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 28 06:41:30 volumio-chambre volumio[1060]: info: CoreCommandRouter::volumioGetState Oct 28 06:41:30 volumio-chambre volumio[1060]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Oct 28 06:41:30 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:30 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:30 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:30 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9818. Oct 28 06:41:30 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:30 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:30 volumio-chambre go-librespot[20839]: Librespot-go daemon starting... Oct 28 06:41:30 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41:30+01:00" level=info msg="generated new device id: bdf3ed725134ed738b61298584d3c5ce48169f60" Oct 28 06:41:30 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41:30+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:30 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41:30+01:00" level=debug msg="obtained new client token: AAAziTxAzijQwPrcOjqJDbekBPrpPOpXmOh7/94xIcDqa3PX4drbDGUYH3OrQWM/CbE7cIMcbXm3Y6JpwU6w28xFP6Gb/5ZcYwZv414kYUFIGBGjUaCFnyd9s4I5Zdyx4H295y+8Q6tciMwGKjLLI8nJt56QxDhmavSExsRcjnegy7sTR7ht/Kq8zlMxuVlWlhNRs6fdPZSkx0BNqClKN3LVzoWQk04CRXmK4Y79WBHR5bmQkmNIGa4xhPTNHw==" Oct 28 06:41:30 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41: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]" Oct 28 06:41:30 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41:30+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:31 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41:31+01:00" level=debug msg="completed challenge" Oct 28 06:41:31 volumio-chambre go-librespot[20839]: time="2024-10-28T06:41:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:31 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:31 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:31 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:33 volumio-chambre volumiologrotate[636]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Oct 28 06:41:33 volumio-chambre volumiologrotate[636]: ls: cannot access 'CHAMBRE': No such file or directory Oct 28 06:41:33 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:33 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:34 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:34 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9819. Oct 28 06:41:34 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:34 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:34 volumio-chambre go-librespot[20888]: Librespot-go daemon starting... Oct 28 06:41:34 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41:34+01:00" level=info msg="generated new device id: 152ffc2a1bc6fcb00c4377f61ae0073a15406a73" Oct 28 06:41:34 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41:34+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:34 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41:34+01:00" level=debug msg="obtained new client token: AAAvHctUkXTKrUNLX3E9gABy6Ll+3pXvSvmY5fp4+LvNcYegQpxCoaGzTnP6r2Gu3DJB46gq8sftxU2NPhUpZm10f57Qa+DcvJKQUIYdhzBFYipENWFXMBu8g5Gd3N+Ye2hs2gWCfPwQEbuIS9deRhNu/+PBsGHkzXNwt5f2KoOCs8Hkfgcy+O4mk4H1b0pabM63ogkt00kFF2K3uDjiFsITat95UZxG4kiNmS7pdLLKQ/uQ8q4SlshanhEEXg==" Oct 28 06:41:34 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 28 06:41:34 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41:34+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:35 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41:35+01:00" level=debug msg="completed challenge" Oct 28 06:41:35 volumio-chambre go-librespot[20888]: time="2024-10-28T06:41:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:35 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:36 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:36 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:36 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:36 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:38 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:38 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9820. Oct 28 06:41:38 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:38 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:38 volumio-chambre go-librespot[20897]: Librespot-go daemon starting... Oct 28 06:41:38 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41:38+01:00" level=info msg="generated new device id: 9ced40100b2bb3b9ad0bd723d49996817403e6fd" Oct 28 06:41:38 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41:38+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:38 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41:38+01:00" level=debug msg="obtained new client token: AACvR45hvvPDoGYsgL4NI82RnXoa3wpKv34wwxQGAbjKxDvqZgug+M5Lr9TlpvGpiSe7oSpzxYghA/jLODbqMNu33c++5T1MANxzTGxrb//VjgJx5Zp5EYDl5V2p82coZPWdRdneptZX2z6AR/YAX4Fki90FvQb3ekwOMzbFR02aa1UICFyU3IhaTcxEHwNHU2DdeejPO1ge5W0Ye8HfbCQqBngXLoa+5vzv0VKkdDb2z0Hawr7qWFJrJwhgag==" Oct 28 06:41:38 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 28 06:41:38 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41:38+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:39 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41:39+01:00" level=debug msg="completed challenge" Oct 28 06:41:39 volumio-chambre go-librespot[20897]: time="2024-10-28T06:41:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:39 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:39 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:39 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:39 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:39 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:42 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:42 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:42 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:42 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9821. Oct 28 06:41:42 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:42 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:42 volumio-chambre go-librespot[20906]: Librespot-go daemon starting... Oct 28 06:41:42 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41:42+01:00" level=info msg="generated new device id: 8e9c6ad514aaa3f02e642fe0b290aec1894dd9cb" Oct 28 06:41:42 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41:42+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:42 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41:42+01:00" level=debug msg="obtained new client token: AAB2VwEXcU1tDCGCuDlkPAcliYT/EO/yFZVqbKg155iOL49xtGVLqVHGJVfbLz++PMmoPYKLsoj+/Tbdb3UoD15LXsIv0tag4w9IZT7x65od594337+DC/tg146dNxWzIeSD+MeLkNxRzYMdpKhNgyprm2ZgVuUfKxxdD/5lb1dbIvwnfzGE+wAc7ej2Nj3HfXD6ROwGYPk4pjs0xiYNf1oKoLlDoQr08nD8oSN5oxvSqp/2BW+66uzZkxP5Zg==" Oct 28 06:41:42 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 28 06:41:42 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41:42+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:43 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:43 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41:43+01:00" level=debug msg="completed challenge" Oct 28 06:41:43 volumio-chambre go-librespot[20906]: time="2024-10-28T06:41:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:43 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:43 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:45 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:45 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:46 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:46 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9822. Oct 28 06:41:46 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:46 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:46 volumio-chambre go-librespot[20914]: Librespot-go daemon starting... Oct 28 06:41:46 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41:46+01:00" level=info msg="generated new device id: 255e442787a9e8bc1be9b6ca83963a4cd8472b97" Oct 28 06:41:46 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41:46+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:46 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41:46+01:00" level=debug msg="obtained new client token: AAB3Qkci4cYSQ5NwXlfZJysKZJ49kH0l2/BYU2IYKbBPco+R+gnMcPE/mVTo0d8sptig6UvM9i/lDkkwhCjh3wq9Lw5Mb4MOztjDqIe/9Gr1DS/qHxLhrXYQXVfe8XxvvobnCPYV1vOortzewnLbdxlFBTM3npjWWXOYko+GmiMScorWGj5PAR1gK7t5HmgzYgZZo1ioI+K0VEdj70NkuUgLptfCa+oVEtxifXZf5cBr2k3E5yjTk/5sRaeyoA==" Oct 28 06:41:46 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:46 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:46 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41: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]" Oct 28 06:41:46 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41:46+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:47 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41:47+01:00" level=debug msg="completed challenge" Oct 28 06:41:47 volumio-chambre go-librespot[20914]: time="2024-10-28T06:41:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:47 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:48 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:48 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:50 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:50 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9823. Oct 28 06:41:50 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:50 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:50 volumio-chambre go-librespot[20922]: Librespot-go daemon starting... Oct 28 06:41:50 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41:50+01:00" level=info msg="generated new device id: f480bb48e7ace5969c8286e686f4b0b9f35e2ea8" Oct 28 06:41:50 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41:50+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:50 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41:50+01:00" level=debug msg="obtained new client token: AAD1PZNSQsrvWhRR9ZIRUfFIOXVhwH3fsH12h9oRVjfUuQ0kav61LkXpViJMs2g4nzHoCUkrjFGlx3Yq9JDbSvb2lfs5nbs0/etMypSu0IBMMKIOe6rCdy0bEm1/Q2JVOl/y020G4lMBX3UQB8I5ivmq0kcrcE4txRKDAthhX78nx56agQ4C5h5zDaCf57eJPvrYmaFfmQv1CNVXs+Xf+IdZNWjdWvp9ZnSrjilrdvb9BZjOhAYqS0qxXdgOwg==" Oct 28 06:41:50 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41: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]" Oct 28 06:41:50 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41:50+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:51 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:51 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41:51+01:00" level=debug msg="completed challenge" Oct 28 06:41:51 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:51 volumio-chambre go-librespot[20922]: time="2024-10-28T06:41:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:51 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:51 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:51 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:54 volumio-chambre volumio[1060]: info: Initializing connection to go-librespot Websocket Oct 28 06:41:54 volumio-chambre volumio[1060]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 28 06:41:54 volumio-chambre systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Oct 28 06:41:54 volumio-chambre systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9824. Oct 28 06:41:54 volumio-chambre systemd[1]: Stopped go-librespot Daemon. Oct 28 06:41:54 volumio-chambre systemd[1]: Started go-librespot Daemon. Oct 28 06:41:54 volumio-chambre go-librespot[20930]: Librespot-go daemon starting... Oct 28 06:41:54 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41:54+01:00" level=info msg="generated new device id: 3183bb25e66b81532c1b62ff60255f1662cef48c" Oct 28 06:41:54 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41:54+01:00" level=debug msg="stored credentials found for lmouldaia" Oct 28 06:41:54 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41:54+01:00" level=debug msg="obtained new client token: AACpUb0NwX8otH9vkzSI0cfSiiYOZj/q3N1DwFtJ4c+hgB29VxQQTBxc8EKtDpkwkYyXoEDcLkOpDwujYUAdZp0SQDpGnZSvhGRFtpOilJxE8cCQ7Lly8NELOkenNVx4xpIqiZa7cDn8+bT0dLVbl8cGxoPdQZw7xnP6KYDhmv9gGcVDYyv0Ox0MJay04mqzKHOM3t/Hh5nEgpkyfRtSfhkIJWCZZSrZHmYl68zasCbJKPnDTS7n5HQRG5Iz+w==" Oct 28 06:41:54 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41: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-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 28 06:41:54 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41:54+01:00" level=debug msg="completed keyexchange" Oct 28 06:41:55 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41:55+01:00" level=debug msg="completed challenge" Oct 28 06:41:55 volumio-chambre go-librespot[20930]: time="2024-10-28T06:41:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Oct 28 06:41:55 volumio-chambre systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 28 06:41:55 volumio-chambre systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 28 06:41:56 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:56 volumio-chambre dhcpcd[1014]: wlan0: reject NAK via 192.168.0.1 Oct 28 06:41:56 volumio-chambre volumio[1060]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 06:41:56 volumio-chambre volumio[1060]: Error: connect ETIMEDOUT 199.232.170.79:80 Oct 28 06:41:56 volumio-chambre volumio[1060]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Oct 28 06:41:56 volumio-chambre volumio[1060]: errno: -110, Oct 28 06:41:56 volumio-chambre volumio[1060]: code: 'ETIMEDOUT', Oct 28 06:41:56 volumio-chambre volumio[1060]: syscall: 'connect', Oct 28 06:41:56 volumio-chambre volumio[1060]: address: '199.232.170.79', Oct 28 06:41:56 volumio-chambre volumio[1060]: port: 80 Oct 28 06:41:56 volumio-chambre volumio[1060]: } Oct 28 06:41:56 volumio-chambre volumio[1060]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 06:41:57 volumio-chambre sudo[20947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-28 06:40 Oct 28 06:41:57 volumio-chambre sudo[20947]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"