-- Logs begin at Sat 2024-04-06 15:10:38 UTC, end at Sat 2024-04-06 16:07:45 UTC. --
Apr 06 16:06:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2250.
Apr 06 16:06:00 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:00 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:00 volumio go-librespot[11629]: Librespot-go daemon starting...
Apr 06 16:06:00 volumio go-librespot[11629]: time="2024-04-06T16:06:00Z" level=info msg="generated new device id: 170883059b2246dfd7d426401f28b5d1f170a7a6"
Apr 06 16:06:00 volumio go-librespot[11629]: time="2024-04-06T16:06:00Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:00 volumio go-librespot[11629]: time="2024-04-06T16:06:00Z" level=debug msg="obtained new client token: AABSU1At0aOU72UN9x+LdZh5GeiDwo6qh1x4+Z44tGSp7aBw/93bU8sz89dWuOHJtkr/04bAc3NwMV4d+yqZEtgbOpLPqS9p01yo5cWRrT2/1vh6zUNiVc/sHF7L2WZRvMJ7l3sxVoC55zTRpc/V2+VFEiDZqHROifA7HU0mfbn5MaUeO4HmGzmzLmJbzpox/pkTazDJrnjXnx9b3qOni5WJcFsA7JDDBywrY4BdcAJQvFvpiYMckwwcKInXmH8="
Apr 06 16:06:00 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:00 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:06:00 volumio go-librespot[11629]: time="2024-04-06T16:06:00Z" level=debug msg="new websocket client"
Apr 06 16:06:01 volumio go-librespot[11629]: time="2024-04-06T16:06:01Z" 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]"
Apr 06 16:06:01 volumio go-librespot[11629]: time="2024-04-06T16:06:01Z" level=debug msg="completed keyexchange"
Apr 06 16:06:01 volumio go-librespot[11629]: time="2024-04-06T16:06:01Z" level=debug msg="completed challenge"
Apr 06 16:06:01 volumio go-librespot[11629]: time="2024-04-06T16:06:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:01 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: mixer
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: output
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: mixer
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: output
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: mixer
Apr 06 16:06:01 volumio volumio[775]: info:
Apr 06 16:06:01 volumio volumio[775]: ---------------------------- MPD announces state update: output
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 10 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 11 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 8 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 8 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand status took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 18 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 17 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 16 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 16 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 15 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 15 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 15 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand clearerror took 14 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 8 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 8 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 8 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 7 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 6 milliseconds
Apr 06 16:06:01 volumio volumio[775]: info: sendMpdCommand playlistinfo took 6 milliseconds
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22045,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:01 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:01 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:01 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:01 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 55ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 55ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 55ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 53ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 54ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 54ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 55ms
Apr 06 16:06:01 volumio volumio[775]: info: ------------------------------ 55ms
Apr 06 16:06:03 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:06:03 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:03 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:06:03 volumio volumio[775]: (node:775) 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: 747)
Apr 06 16:06:03 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:04 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:04 volumio volumio[775]: info:
Apr 06 16:06:04 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:04 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:04 volumio volumio[775]: info:
Apr 06 16:06:04 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:04 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:04 volumio volumio[775]: info:
Apr 06 16:06:04 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:04 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand status took 5 milliseconds
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand status took 4 milliseconds
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand status took 4 milliseconds
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand clearerror took 6 milliseconds
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand clearerror took 6 milliseconds
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand clearerror took 5 milliseconds
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand playlistinfo took 3 milliseconds
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand playlistinfo took 3 milliseconds
Apr 06 16:06:04 volumio volumio[775]: info: sendMpdCommand playlistinfo took 2 milliseconds
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:04 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:04 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:04 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:04 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:04 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:04 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:04 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus play
Apr 06 16:06:04 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:04 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:04 volumio volumio[775]: info: ------------------------------ 20ms
Apr 06 16:06:04 volumio volumio[775]: info: ------------------------------ 20ms
Apr 06 16:06:04 volumio volumio[775]: info: ------------------------------ 19ms
Apr 06 16:06:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2251.
Apr 06 16:06:04 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:04 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:04 volumio go-librespot[11643]: Librespot-go daemon starting...
Apr 06 16:06:04 volumio go-librespot[11643]: time="2024-04-06T16:06:04Z" level=info msg="generated new device id: 20274407e92cc06f495c12271eb199f9197b0ae6"
Apr 06 16:06:04 volumio go-librespot[11643]: time="2024-04-06T16:06:04Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:05 volumio go-librespot[11643]: time="2024-04-06T16:06:05Z" level=debug msg="obtained new client token: AAC9SWM2NfAowzbRqFUZozttirADGc+2O0eMGxNHdY4BiLnxh8jPnymyla6YRGvPqkRubGu85R192gAdQ3XrqoIfMSTlsGxNIjZYdqo6R3xaoD7lu6TAQH//fEIlKVEwei7KIiS2jADNaqFXGG81HEbofZmRtQZeXYc45LefE6uar0C9NFlAFCXxq9ylbFCkTpSYSvE7y8yTx4hK+OHx56070sbQzJvm34GQ1embDbrClkvjk7hstt1KQ1YK"
Apr 06 16:06:05 volumio go-librespot[11643]: time="2024-04-06T16:06:05Z" 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]"
Apr 06 16:06:05 volumio go-librespot[11643]: time="2024-04-06T16:06:05Z" level=debug msg="completed keyexchange"
Apr 06 16:06:05 volumio go-librespot[11643]: time="2024-04-06T16:06:05Z" level=debug msg="completed challenge"
Apr 06 16:06:05 volumio go-librespot[11643]: time="2024-04-06T16:06:05Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:07 volumio volumio[775]: verbose: New Socket.io Connection to 192.168.2.180 from 192.168.2.13 UA: okhttp/4.9.2 Total Clients: 6
Apr 06 16:06:07 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:07 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 06 16:06:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 06 16:06:07 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:07 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:09 volumio sudo[11652]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 06 16:06:09 volumio sudo[11652]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 06 16:06:09 volumio sudo[11652]: pam_unix(sudo:session): session closed for user root
Apr 06 16:06:09 volumio sudo[11655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 06 16:06:09 volumio sudo[11655]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 06 16:06:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2252.
Apr 06 16:06:09 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:09 volumio sudo[11655]: pam_unix(sudo:session): session closed for user root
Apr 06 16:06:09 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:09 volumio go-librespot[11657]: Librespot-go daemon starting...
Apr 06 16:06:09 volumio go-librespot[11657]: time="2024-04-06T16:06:09Z" level=info msg="generated new device id: 62a425ebfbadee9336caf00762d7338ed5146823"
Apr 06 16:06:09 volumio go-librespot[11657]: time="2024-04-06T16:06:09Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:09 volumio volumio[775]: verbose: New Socket.io Connection to 192.168.2.180 from 192.168.2.13 UA: okhttp/4.9.2 Total Clients: 7
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:09 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 06 16:06:09 volumio go-librespot[11657]: time="2024-04-06T16:06:09Z" level=debug msg="obtained new client token: AABHjcabybPlnQZgybkFuBnQAzpCaAK4Ki+fKGEkl2jMGL8mYftL47A/HtYHN8uJMs4o6rNXVV46TlOVjQ0fzMUjsbYFTC2LQ6cK+xJg3VEygFNRgGj771OrhYja2QKFL7aQKCP2qnquirff26JHhKlCLNWOWWFcSYS7InpBEpKBS1LvHpR/YZmeIUp2MiYW84ftxnKDTz1bDRrKkfHRD/uaI6hOvB4uacJHNbF6VK6MxmGUGpcXQMpCVX3Uq5Y="
Apr 06 16:06:09 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:09 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:09 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:09 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:09 volumio volumio[775]: info: Listing playlists
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 06 16:06:09 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 06 16:06:09 volumio go-librespot[11657]: time="2024-04-06T16:06:09Z" 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]"
Apr 06 16:06:09 volumio go-librespot[11657]: time="2024-04-06T16:06:09Z" level=debug msg="completed keyexchange"
Apr 06 16:06:10 volumio go-librespot[11657]: time="2024-04-06T16:06:10Z" level=debug msg="completed challenge"
Apr 06 16:06:10 volumio go-librespot[11657]: time="2024-04-06T16:06:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:10 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:10 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:11 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 06 16:06:11 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:11 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:11 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:11 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:11 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:11 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:11 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:12 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:12 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 06 16:06:12 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:12 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:12 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:12 volumio volumio[775]: info: CoreCommandRouter::volumioGetQueue
Apr 06 16:06:12 volumio volumio[775]: info: CoreStateMachine::getQueue
Apr 06 16:06:12 volumio volumio[775]: info: CorePlayQueue::getQueue
Apr 06 16:06:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2253.
Apr 06 16:06:13 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:13 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:13 volumio go-librespot[11665]: Librespot-go daemon starting...
Apr 06 16:06:13 volumio go-librespot[11665]: time="2024-04-06T16:06:13Z" level=info msg="generated new device id: 9f9fa5fab448c70a31b9fef31a8d191afdf630ff"
Apr 06 16:06:13 volumio go-librespot[11665]: time="2024-04-06T16:06:13Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:13 volumio go-librespot[11665]: time="2024-04-06T16:06:13Z" level=debug msg="obtained new client token: AADjf2EYiChdA7u+bmrPzyTzOEqGnrdA2aD3KN4e9qZjoz7yc8xk6m4d58MZ2VlF5O7J0ilvWKK4zhF4T7BjELuxW3SIj1QcZ/gmL2T2NQ/aoKh7svZPuQqaNZItdJslmD0m6ZeCjJCH8Fn74m8NEBWHfwl/Vu+CXUJTNc559fHl4/rsww3jH+Ol/c1OC45rGNkYYeNsQhY21EEcgW0p7eCwG5dmlkV/U0wdPyraRkXqqEFf1ioZuVn0B02cR28="
Apr 06 16:06:13 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:13 volumio go-librespot[11665]: time="2024-04-06T16:06:13Z" level=debug msg="new websocket client"
Apr 06 16:06:13 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:06:13 volumio go-librespot[11665]: time="2024-04-06T16:06:13Z" 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]"
Apr 06 16:06:13 volumio go-librespot[11665]: time="2024-04-06T16:06:13Z" level=debug msg="completed keyexchange"
Apr 06 16:06:14 volumio go-librespot[11665]: time="2024-04-06T16:06:14Z" level=debug msg="completed challenge"
Apr 06 16:06:14 volumio go-librespot[11665]: time="2024-04-06T16:06:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:14 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:06:15 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 06 16:06:15 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 06 16:06:16 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:06:16 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:16 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:06:16 volumio volumio[775]: (node:775) 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: 748)
Apr 06 16:06:16 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Apr 06 16:06:16 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:16 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:17 volumio sudo[11674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 06 16:06:17 volumio sudo[11674]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 06 16:06:17 volumio sudo[11674]: pam_unix(sudo:session): session closed for user root
Apr 06 16:06:17 volumio sudo[11677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 06 16:06:17 volumio sudo[11677]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 06 16:06:17 volumio sudo[11677]: pam_unix(sudo:session): session closed for user root
Apr 06 16:06:17 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:17 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:17 volumio volumio[775]: verbose: New Socket.io Connection to 192.168.2.180 from 192.168.2.13 UA: okhttp/4.9.2 Total Clients: 7
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:17 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 06 16:06:17 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:17 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:17 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:17 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:17 volumio volumio[775]: info: Listing playlists
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 06 16:06:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2254.
Apr 06 16:06:17 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:17 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 06 16:06:17 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:17 volumio go-librespot[11679]: Librespot-go daemon starting...
Apr 06 16:06:17 volumio go-librespot[11679]: time="2024-04-06T16:06:17Z" level=info msg="generated new device id: 3bfcefd6c9577912cda1703a11aac76c4f29ff5e"
Apr 06 16:06:17 volumio go-librespot[11679]: time="2024-04-06T16:06:17Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:17 volumio go-librespot[11679]: time="2024-04-06T16:06:17Z" level=debug msg="obtained new client token: AAAJZm449QYKpsHVpP9ZU/f90pj7WZGKa39EEVL3nQ5PAB08RpMo2wXY6BsHFaeCyLrmKB6z4hOmU3oMjPtJMs1te8epvX79ajCIN2Da0cWZR/EQtYduOTP00I8qeM2cPu/NQQl26cWKc4KqQi7Y0D8CiZFQl8bIF+0kpAc0XOcVjY12i9Ecwvo3PFChaKm1BeqGDhEsxlto/LkOFkwvZao5s+9uIXhn2noMfrjxWBAPaT+ADoDHEE5dru9oeJ0="
Apr 06 16:06:18 volumio go-librespot[11679]: time="2024-04-06T16:06:18Z" 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]"
Apr 06 16:06:18 volumio go-librespot[11679]: time="2024-04-06T16:06:18Z" level=debug msg="completed keyexchange"
Apr 06 16:06:18 volumio go-librespot[11679]: time="2024-04-06T16:06:18Z" level=debug msg="completed challenge"
Apr 06 16:06:18 volumio volumio[775]: info: CoreCommandRouter::volumioGetQueue
Apr 06 16:06:18 volumio volumio[775]: info: CoreStateMachine::getQueue
Apr 06 16:06:18 volumio volumio[775]: info: CorePlayQueue::getQueue
Apr 06 16:06:18 volumio go-librespot[11679]: time="2024-04-06T16:06:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:19 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 06 16:06:19 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:19 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:19 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:19 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:19 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:19 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:19 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 06 16:06:20 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:20 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:20 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:20 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:20 volumio volumio[775]: info: Preload queue cleared
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioReplaceandPlayItems
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::ClearQueue
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::stPlaybackTimer
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::updateTrackBlock
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrackBlock
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::serviceStop
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::serviceStop
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::stop
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand stop
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::clearPlayQueue
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::saveQueue
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushQueue
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::addQueueItems
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::addQueueItems
Apr 06 16:06:20 volumio volumio[775]: info: Preload queue cleared
Apr 06 16:06:20 volumio volumio[775]: info: Adding Item to queue: music-library/USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata
Apr 06 16:06:20 volumio volumio[775]: info: Using cached record of: music-library/USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushQueue
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::saveQueue
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::updateTrackBlock
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrackBlock
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPlay
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::play index 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::play index undefined
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::startPlaybackTimer
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::clearAddPlayTracks USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand stop
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand stop took 19 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand stop took 4 milliseconds
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clear
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:20 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand status took 4 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand clear took 4 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3"
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:20 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: No code
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:20 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: No code
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 15ms
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 15ms
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:20 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:20 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:20 volumio volumio[775]: error: updateQueue error: null
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:20 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 23ms
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand playlistinfo took 22 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3" took 22 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 10ms
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 10ms
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand play
Apr 06 16:06:20 volumio volumio[775]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 31ms
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:20 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:20 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 12ms
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand play took 10 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 8ms
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 7ms
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:20 volumio volumio[775]: info:
Apr 06 16:06:20 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand status took 10 milliseconds
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand status took 10 milliseconds
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand status took 9 milliseconds
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand clearerror took 17 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand clearerror took 16 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand clearerror took 16 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand playlistinfo took 13 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:20 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:20 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:20 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:20 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:20 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:20 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:20 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:20 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 49ms
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 48ms
Apr 06 16:06:20 volumio volumio[775]: info: ------------------------------ 46ms
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:21 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:21 volumio volumio[775]: info: Preload queue cleared
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioReplaceandPlayItems
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::ClearQueue
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::clearPlayQueue
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::saveQueue
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushQueue
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::addQueueItems
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::addQueueItems
Apr 06 16:06:21 volumio volumio[775]: info: Preload queue cleared
Apr 06 16:06:21 volumio volumio[775]: info: Adding Item to queue: music-library/USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata
Apr 06 16:06:21 volumio volumio[775]: info: Using cached record of: music-library/USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushQueue
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::saveQueue
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::updateTrackBlock
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrackBlock
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPlay
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::play index 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::play index undefined
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::startPlaybackTimer
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::clearAddPlayTracks USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand stop
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand stop took 4 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clear
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:21 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 4 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand clear took 4 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 2 milliseconds
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3"
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: No code
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: No code
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 19ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 20ms
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:21 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:21 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:21 volumio volumio[775]: error: updateQueue error: null
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:21 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 20ms
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 19 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3" took 19 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 3ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 2ms
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand play
Apr 06 16:06:21 volumio volumio[775]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 26ms
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:21 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:21 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 7ms
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand play took 6 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 5ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 4ms
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 6 milliseconds
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 5 milliseconds
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 5 milliseconds
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: info:
Apr 06 16:06:21 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 12 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand clearerror took 10 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand clearerror took 10 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand clearerror took 9 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 7 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 6 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 7 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 6 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand status took 5 milliseconds
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 29ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 28ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 28ms
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand clearerror took 18 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 16 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 16 milliseconds
Apr 06 16:06:21 volumio volumio[775]: info: sendMpdCommand playlistinfo took 15 milliseconds
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:21 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:21 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:21 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:21 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 42ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 34ms
Apr 06 16:06:21 volumio volumio[775]: info: ------------------------------ 34ms
Apr 06 16:06:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2255.
Apr 06 16:06:21 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:21 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:21 volumio go-librespot[11690]: Librespot-go daemon starting...
Apr 06 16:06:21 volumio go-librespot[11690]: time="2024-04-06T16:06:21Z" level=info msg="generated new device id: fbb3a2c2210f77fd5555f78aaebfa25f9996c7a1"
Apr 06 16:06:21 volumio go-librespot[11690]: time="2024-04-06T16:06:21Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:22 volumio go-librespot[11690]: time="2024-04-06T16:06:22Z" level=debug msg="obtained new client token: AABtjFevVKcpYnqpa4wLUvHKHGrUXafGZLKiXXMS3xwAoj+KQG+pnQnnXbaA8vfNZMUmbBsRpQlDNiYhCxo2Ev/ypTpF07N+PvxnlvE08CKm+EG/PBtZVxR8ouD0yhFaYgdMVzbLAAm36G7kpyTgfXinypQ2Pt7ngp6/RijYtnaJIUNARjByJ/nkLfFHFA8AJa7cqUUtyDPizEmzrBB1rPLd2ug76pLA6hcpJKjEGzPTRM81amC8BZQxSuB+"
Apr 06 16:06:22 volumio go-librespot[11690]: time="2024-04-06T16:06:22Z" 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]"
Apr 06 16:06:22 volumio go-librespot[11690]: time="2024-04-06T16:06:22Z" level=debug msg="completed keyexchange"
Apr 06 16:06:22 volumio go-librespot[11690]: time="2024-04-06T16:06:22Z" level=debug msg="completed challenge"
Apr 06 16:06:22 volumio go-librespot[11690]: time="2024-04-06T16:06:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:23 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:23 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2256.
Apr 06 16:06:26 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:26 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:26 volumio go-librespot[11701]: Librespot-go daemon starting...
Apr 06 16:06:26 volumio go-librespot[11701]: time="2024-04-06T16:06:26Z" level=info msg="generated new device id: 028c730957a9338f1157cbfa68ad57109f22d275"
Apr 06 16:06:26 volumio go-librespot[11701]: time="2024-04-06T16:06:26Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:26 volumio go-librespot[11701]: time="2024-04-06T16:06:26Z" level=debug msg="obtained new client token: AABn7kzlvPKeyfg/ySB73saYReNa9PESFgPD4gd1wBGUt5Eq1pHBOt/kbmVGBA+nqpChovVuL5pxedDNZmPjYThQZ7S+iCwOCLiXTi6PBzzAw6qAUI6wWLBst5uNrFbSZ9R8plHFk6pS1YAbFJU1PMskoHsu/DDUSOb1dgZGJa7aXXDksY/CU1Wjc1Lm1fxMiGnzur7rZwdhlNZFalnX84orJSfiuTxqhRX5VpTaSIeLTpKr+dLg4RQexcaGawM="
Apr 06 16:06:26 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:26 volumio go-librespot[11701]: time="2024-04-06T16:06:26Z" level=debug msg="new websocket client"
Apr 06 16:06:26 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:06:26 volumio go-librespot[11701]: time="2024-04-06T16:06:26Z" 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]"
Apr 06 16:06:26 volumio volumio[775]: verbose: New Socket.io Connection to 192.168.2.180 from 192.168.2.13 UA: okhttp/4.9.2 Total Clients: 6
Apr 06 16:06:26 volumio go-librespot[11701]: time="2024-04-06T16:06:26Z" level=debug msg="completed keyexchange"
Apr 06 16:06:27 volumio go-librespot[11701]: time="2024-04-06T16:06:27Z" level=debug msg="completed challenge"
Apr 06 16:06:27 volumio go-librespot[11701]: time="2024-04-06T16:06:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:27 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:06:29 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:06:29 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:29 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:06:29 volumio volumio[775]: (node:775) 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: 749)
Apr 06 16:06:29 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Apr 06 16:06:29 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:29 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:30 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:30 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2257.
Apr 06 16:06:30 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:30 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:30 volumio go-librespot[11709]: Librespot-go daemon starting...
Apr 06 16:06:30 volumio go-librespot[11709]: time="2024-04-06T16:06:30Z" level=info msg="generated new device id: b3b10e94fe34a1322b659701684d2b517fcd7a6f"
Apr 06 16:06:30 volumio go-librespot[11709]: time="2024-04-06T16:06:30Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:30 volumio go-librespot[11709]: time="2024-04-06T16:06:30Z" level=debug msg="obtained new client token: AABiP5JrxyYvBMJzDBC1FeHBW+GZcq2OZ+cyWe05x1ct00RxEoEumWb//D9XjnXWrba7UAwWGs+hTLxS12RsdGHdjju3YL6qFDn8LrLvVBZ1iKTTTweQy3FmRLNPKBDaqSyv0O0Og+PHOuarZjML7346mlXe7gw8pwJIzRy2ZOFccMf2Cy+tVp90JA52j66j4vLpG9ikmjcvecyta8FziG5i2ZRlczUNwsLws40qrY7m+YCCySaFL5TVkX/iJ3w="
Apr 06 16:06:30 volumio go-librespot[11709]: time="2024-04-06T16:06:30Z" 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]"
Apr 06 16:06:30 volumio go-librespot[11709]: time="2024-04-06T16:06:30Z" level=debug msg="completed keyexchange"
Apr 06 16:06:31 volumio go-librespot[11709]: time="2024-04-06T16:06:31Z" level=debug msg="completed challenge"
Apr 06 16:06:31 volumio go-librespot[11709]: time="2024-04-06T16:06:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:32 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:32 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:32 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:32 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:32 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:32 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:33 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:33 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2258.
Apr 06 16:06:34 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:34 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:34 volumio go-librespot[11718]: Librespot-go daemon starting...
Apr 06 16:06:34 volumio go-librespot[11718]: time="2024-04-06T16:06:34Z" level=info msg="generated new device id: b6a2fcd5336877ff02f1d60df8069f669f99cd81"
Apr 06 16:06:34 volumio go-librespot[11718]: time="2024-04-06T16:06:34Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:34 volumio go-librespot[11718]: time="2024-04-06T16:06:34Z" level=debug msg="obtained new client token: AAA866L8YTbNIzllv+M+FycqPPfUG3OHkfjT9vgmLXJPFetHQ+w8kbzD7lxowCY7hVPMHY2KnYmqJG6x6JyTdKuxV1bPmesK93zIpFLIdl6IHh/YDllf0DaYGExOqVKiMO77sdh4/1L6mM8jgeL/2jxjDW1YI5lt9DM2jSdbMM64TLhXzBa1vabWEhbBchkA7yWOEyvTPJvXg1f4Vk3JiYGseMCjz626q5gmRZGFsM5+lIgHUaRB9ZnXIxiHu+A="
Apr 06 16:06:35 volumio go-librespot[11718]: time="2024-04-06T16:06:35Z" 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]"
Apr 06 16:06:35 volumio go-librespot[11718]: time="2024-04-06T16:06:35Z" level=debug msg="completed keyexchange"
Apr 06 16:06:35 volumio go-librespot[11718]: time="2024-04-06T16:06:35Z" level=debug msg="completed challenge"
Apr 06 16:06:35 volumio go-librespot[11718]: time="2024-04-06T16:06:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:36 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:36 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2259.
Apr 06 16:06:38 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:38 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:38 volumio go-librespot[11726]: Librespot-go daemon starting...
Apr 06 16:06:38 volumio go-librespot[11726]: time="2024-04-06T16:06:38Z" level=info msg="generated new device id: 88f28c2fb029a874745cb40d50fef56866390609"
Apr 06 16:06:38 volumio go-librespot[11726]: time="2024-04-06T16:06:38Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:39 volumio go-librespot[11726]: time="2024-04-06T16:06:39Z" level=debug msg="obtained new client token: AABd9gv1uQgwFRKbPo1FlHwnAd3inpaFtZYG3/DDFV7TKQR2xF+KlOOjnmSKLOwcqTWPCxDb3t+r6NG6SSnrg7c4cck3L4/SJWuMZmS+jdb/MNCWMfNRQsxQuLoM29BffzGzMzmGr8MYCPVtPDCgepqMG2JqbnrwWtLAoR7lnQhNeJylDI+c39CyhJ37HaBQAXoyO1haQevmtCPK4odey1RIYubLzcHEQQJy3VCziz5N83cj1SUERO69P5Gc"
Apr 06 16:06:39 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:39 volumio go-librespot[11726]: time="2024-04-06T16:06:39Z" level=debug msg="new websocket client"
Apr 06 16:06:39 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:06:39 volumio go-librespot[11726]: time="2024-04-06T16:06:39Z" 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]"
Apr 06 16:06:39 volumio go-librespot[11726]: time="2024-04-06T16:06:39Z" level=debug msg="completed keyexchange"
Apr 06 16:06:39 volumio go-librespot[11726]: time="2024-04-06T16:06:39Z" level=debug msg="completed challenge"
Apr 06 16:06:39 volumio go-librespot[11726]: time="2024-04-06T16:06:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:39 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:06:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:41 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:41 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:41 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:41 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:41 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:41 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:42 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:06:42 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:42 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:06:42 volumio volumio[775]: (node:775) 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: 750)
Apr 06 16:06:42 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Apr 06 16:06:42 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:42 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:42 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:42 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2260.
Apr 06 16:06:43 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:43 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:43 volumio go-librespot[11735]: Librespot-go daemon starting...
Apr 06 16:06:43 volumio go-librespot[11735]: time="2024-04-06T16:06:43Z" level=info msg="generated new device id: 12d7273c19a0b2aff9465a4425bf6dbe1e6198e9"
Apr 06 16:06:43 volumio go-librespot[11735]: time="2024-04-06T16:06:43Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:43 volumio go-librespot[11735]: time="2024-04-06T16:06:43Z" level=debug msg="obtained new client token: AACTP5dqQlf6trGYMVxceVIE+56FV3XVzP5nKSJh4Lli8JRTK8Qpeg7d5bnOSqI8f94cudwTtBATsa36Ic+DxceZP3MnzjT06HJ5aYYp4p0R/oRwGWQ851/HXt1WUyoF457S8IfV9RzxeTRlnbX1SZWDT6H1Z8rjhpDoK1K/tLiapSwPm+uw3mcHAy/iOdW6/s85yXlcB4RlpaOaY+oBxBxNmg5XGQ55a2Z+0HBcOaWmoPZ660isBpjK4HcRoQI="
Apr 06 16:06:43 volumio volumio[775]: info:
Apr 06 16:06:43 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:43 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:43 volumio volumio[775]: info:
Apr 06 16:06:43 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:43 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:43 volumio volumio[775]: info:
Apr 06 16:06:43 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:43 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand clearerror took 8 milliseconds
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand clearerror took 7 milliseconds
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand clearerror took 6 milliseconds
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand playlistinfo took 4 milliseconds
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand playlistinfo took 4 milliseconds
Apr 06 16:06:43 volumio volumio[775]: info: sendMpdCommand playlistinfo took 4 milliseconds
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:43 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:43 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:43 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:43 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:43 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:43 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:43 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:43 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:43 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:43 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:43 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:43 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:43 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:43 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:43 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:43 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:43 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:43 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:43 volumio volumio[775]: info: ------------------------------ 20ms
Apr 06 16:06:43 volumio volumio[775]: info: ------------------------------ 21ms
Apr 06 16:06:43 volumio volumio[775]: info: ------------------------------ 20ms
Apr 06 16:06:43 volumio go-librespot[11735]: time="2024-04-06T16:06:43Z" 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]"
Apr 06 16:06:44 volumio go-librespot[11735]: time="2024-04-06T16:06:44Z" level=debug msg="completed keyexchange"
Apr 06 16:06:44 volumio go-librespot[11735]: time="2024-04-06T16:06:44Z" level=debug msg="completed challenge"
Apr 06 16:06:44 volumio go-librespot[11735]: time="2024-04-06T16:06:44Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:45 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:45 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2261.
Apr 06 16:06:47 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:47 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:47 volumio go-librespot[11745]: Librespot-go daemon starting...
Apr 06 16:06:47 volumio go-librespot[11745]: time="2024-04-06T16:06:47Z" level=info msg="generated new device id: 84d36081cb46a6345885694c1948622c9b49fe16"
Apr 06 16:06:47 volumio go-librespot[11745]: time="2024-04-06T16:06:47Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:48 volumio go-librespot[11745]: time="2024-04-06T16:06:48Z" level=debug msg="obtained new client token: AACvodicgYdHoqiRdWrRUvdVJ6aDL0gV97VTbapvx9titCXlWNHX6+HMf30NIhPAU4IGXMQRSAL18rCJWhWtVit9Vj3yZKILobFn2wuTYy3azjWG224VNgUG4lRxRDMBc9TGYuII0ubrPEyyL9IICtacjwS2BfmEy31/Z8L073KXQXz3ZfoHRjb+wPNgTfHT4qVoL69Q16VIo4S66/E0rAxbDtiRiY7uDb1YYLFGxyhWMguXv0W4Ppj/qpzX"
Apr 06 16:06:48 volumio go-librespot[11745]: time="2024-04-06T16:06:48Z" 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]"
Apr 06 16:06:48 volumio go-librespot[11745]: time="2024-04-06T16:06:48Z" level=debug msg="completed keyexchange"
Apr 06 16:06:48 volumio go-librespot[11745]: time="2024-04-06T16:06:48Z" level=debug msg="completed challenge"
Apr 06 16:06:48 volumio go-librespot[11745]: time="2024-04-06T16:06:48Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:48 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:48 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:50 volumio volumio[775]: verbose: New Socket.io Connection to 192.168.2.180 from 192.168.2.13 UA: okhttp/4.9.2 Total Clients: 7
Apr 06 16:06:50 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:50 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:50 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 06 16:06:50 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 06 16:06:51 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:51 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2262.
Apr 06 16:06:52 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:52 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:52 volumio go-librespot[11753]: Librespot-go daemon starting...
Apr 06 16:06:52 volumio go-librespot[11753]: time="2024-04-06T16:06:52Z" level=info msg="generated new device id: 2f6c336d0bcc7c6fd61986537573391f6061074f"
Apr 06 16:06:52 volumio go-librespot[11753]: time="2024-04-06T16:06:52Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:52 volumio go-librespot[11753]: time="2024-04-06T16:06:52Z" level=debug msg="obtained new client token: AAAB/6NKPTnKEyP4bFKedgOrZ3t5h6qV0eQg7Hfw9EuuEmgjCdJVns3XDhcC7CWUKJNJpagNYDNealsgHQgNJrPi9sm17RntzbAOz/8GfkynZG5H+HOVdfllv+a/SYs7hmmnD81T4mrUZEAMHqxCH5PJgSCaaHwskypWVshMFZv8qCnkMwnDS4x6Bu7NiLji5hDqP86P8zfQpTpH8B0sKEpDWjkfuP07lslRnxohJ1BtfxCZbGupcIcF6EtI+S8="
Apr 06 16:06:52 volumio sudo[11762]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 06 16:06:52 volumio sudo[11762]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 06 16:06:52 volumio sudo[11762]: pam_unix(sudo:session): session closed for user root
Apr 06 16:06:52 volumio sudo[11765]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 06 16:06:52 volumio sudo[11765]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 06 16:06:52 volumio sudo[11765]: pam_unix(sudo:session): session closed for user root
Apr 06 16:06:52 volumio go-librespot[11753]: time="2024-04-06T16:06:52Z" 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]"
Apr 06 16:06:52 volumio volumio[775]: verbose: New Socket.io Connection to 192.168.2.180 from 192.168.2.13 UA: okhttp/4.9.2 Total Clients: 8
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:52 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 06 16:06:52 volumio go-librespot[11753]: time="2024-04-06T16:06:52Z" level=debug msg="completed keyexchange"
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 06 16:06:52 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:52 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:52 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:52 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:52 volumio volumio[775]: info: Listing playlists
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 06 16:06:52 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 06 16:06:53 volumio go-librespot[11753]: time="2024-04-06T16:06:53Z" level=debug msg="completed challenge"
Apr 06 16:06:53 volumio go-librespot[11753]: time="2024-04-06T16:06:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 06 16:06:54 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:54 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:54 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:54 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:54 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::volumioPlay
Apr 06 16:06:54 volumio volumio[775]: info: CoreStateMachine::play index undefined
Apr 06 16:06:54 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:54 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:54 volumio volumio[775]: info: CoreStateMachine::startPlaybackTimer
Apr 06 16:06:54 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::clearAddPlayTracks USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand stop
Apr 06 16:06:54 volumio volumio[775]: info: sendMpdCommand stop took 1 milliseconds
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clear
Apr 06 16:06:54 volumio volumio[775]: info:
Apr 06 16:06:54 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:54 volumio volumio[775]: info:
Apr 06 16:06:54 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:54 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:54 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:54 volumio volumio[775]: info: sendMpdCommand clear took 1 milliseconds
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3"
Apr 06 16:06:54 volumio volumio[775]: info:
Apr 06 16:06:54 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:54 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:54 volumio volumio[775]: info:
Apr 06 16:06:54 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:54 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:54 volumio volumio[775]: error: updateQueue error: null
Apr 06 16:06:54 volumio volumio[775]: info:
Apr 06 16:06:54 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:54 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:54 volumio volumio[775]: info: sendMpdCommand status took 3 milliseconds
Apr 06 16:06:54 volumio volumio[775]: info: ------------------------------ 3ms
Apr 06 16:06:54 volumio volumio[775]: info: sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3" took 3 milliseconds
Apr 06 16:06:54 volumio volumio[775]: info: sendMpdCommand status took 2 milliseconds
Apr 06 16:06:54 volumio volumio[775]: info: sendMpdCommand status took 2 milliseconds
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand play
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:54 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:54 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:54 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:54 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:54 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: No code
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: No code
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: No code
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 33ms
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 32ms
Apr 06 16:06:55 volumio volumio[775]: info:
Apr 06 16:06:55 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:55 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:55 volumio volumio[775]: info:
Apr 06 16:06:55 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:55 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:55 volumio volumio[775]: info:
Apr 06 16:06:55 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:55 volumio volumio[775]: info:
Apr 06 16:06:55 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 34ms
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand play took 33 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 4ms
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 3ms
Apr 06 16:06:55 volumio volumio[775]: info:
Apr 06 16:06:55 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:55 volumio volumio[775]: info:
Apr 06 16:06:55 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand status took 15 milliseconds
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand status took 17 milliseconds
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand status took 17 milliseconds
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand status took 16 milliseconds
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand clearerror took 15 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand clearerror took 13 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand clearerror took 13 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand playlistinfo took 8 milliseconds
Apr 06 16:06:55 volumio volumio[775]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:55 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:55 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:55 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 48ms
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 47ms
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 46ms
Apr 06 16:06:55 volumio volumio[775]: info: ------------------------------ 45ms
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:55 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 06 16:06:55 volumio volumio[775]: info: Received Get System Info
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:06:55 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:06:55 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:55 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:06:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:06:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2263.
Apr 06 16:06:56 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:06:56 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:06:56 volumio go-librespot[11771]: Librespot-go daemon starting...
Apr 06 16:06:56 volumio go-librespot[11771]: time="2024-04-06T16:06:56Z" level=info msg="generated new device id: 883a08511e9fe610352133e8d9dfdc47a4e178c2"
Apr 06 16:06:56 volumio go-librespot[11771]: time="2024-04-06T16:06:56Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:06:56 volumio go-librespot[11771]: time="2024-04-06T16:06:56Z" level=debug msg="obtained new client token: AABuA1DySGPcsn5nFl4FMA28AOcLNpbdiehy99rUoi7r9kFZlt5qKF+VOrUP01brWfxFtOexqKmG3g1eEqnTo9gxjFqurac9iHQCVLVu3H+j1fqp0yP4O6tcQ5vZyXfwrAyek0tAujzTPe++eBUwQDyU7gJvdxNgQpBVDUF8UvfoD/8tYe6yFxpAj5jbY9f+9Mo6i7A/XAHc8z363XnLx2aVW0uQAPE5cLAaQ7S4wT9aqZ25yyN9oi5y1NQVtnI="
Apr 06 16:06:56 volumio go-librespot[11771]: time="2024-04-06T16:06:56Z" 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]"
Apr 06 16:06:56 volumio go-librespot[11771]: time="2024-04-06T16:06:56Z" level=debug msg="completed keyexchange"
Apr 06 16:06:57 volumio go-librespot[11771]: time="2024-04-06T16:06:57Z" level=debug msg="completed challenge"
Apr 06 16:06:57 volumio go-librespot[11771]: time="2024-04-06T16:06:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:06:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:06:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPlay
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::play index undefined
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::startPlaybackTimer
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::clearAddPlayTracks USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand stop
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand stop took 2 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clear
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:57 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand status took 4 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand clear took 4 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand status took 2 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand status took 2 milliseconds
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3"
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:57 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: No code
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Apr 06 16:06:57 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState stateService stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: No code
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 25ms
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 25ms
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:57 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:57 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:57 volumio volumio[775]: error: updateQueue error: null
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:57 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 28ms
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand playlistinfo took 27 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand add "USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3" took 26 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 4ms
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 4ms
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand play
Apr 06 16:06:57 volumio volumio[775]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 34ms
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:57 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces system playlist update
Apr 06 16:06:57 volumio volumio[775]: info: Ignoring MPD Status Update
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 19ms
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand play took 17 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 15ms
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 14ms
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:57 volumio volumio[775]: info:
Apr 06 16:06:57 volumio volumio[775]: ---------------------------- MPD announces state update: player
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::getState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand status
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand status took 7 milliseconds
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand status took 7 milliseconds
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand clearerror
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand status took 8 milliseconds
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseState
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand clearerror took 8 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand clearerror took 7 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand clearerror took 6 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand playlistinfo took 3 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand playlistinfo took 2 milliseconds
Apr 06 16:06:57 volumio volumio[775]: info: sendMpdCommand playlistinfo took 2 milliseconds
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:57 volumio volumio[775]: verbose: ControllerMpd::parseTrackInfo
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:57 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:57 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: ControllerMpd::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::servicePushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":323,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sposa son disprezzata (feat. Aciel Martinez Pol)","artist":"䄀挀椀攀氀 䴀愀爀琀椀渀攀稀 倀漀氀","album":"Sposa son disprezzata (feat. Aciel Martinez Pol)","uri":"USB/Elements/PLAYLISTS 2024/Sposa Son Disprezzata/Sposa Son Disprezzata/01 - Sposa son disprezzata (feat. Aciel Martinez Pol).mp3","trackType":"mp3"}
Apr 06 16:06:57 volumio volumio[775]: verbose: CURRENT POSITION 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState stateService pause
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::syncState currentStatus stop
Apr 06 16:06:57 volumio volumio[775]: info: CoreStateMachine::pushState
Apr 06 16:06:57 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:06:57 volumio volumio[775]: info: CoreCommandRouter::volumioPushState
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 34ms
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 32ms
Apr 06 16:06:57 volumio volumio[775]: info: ------------------------------ 32ms
Apr 06 16:06:57 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:06:57 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:06:59 volumio volumio[775]: info: CoreCommandRouter::volumioGetQueue
Apr 06 16:06:59 volumio volumio[775]: info: CoreStateMachine::getQueue
Apr 06 16:06:59 volumio volumio[775]: info: CorePlayQueue::getQueue
Apr 06 16:07:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2264.
Apr 06 16:07:00 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:00 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:00 volumio go-librespot[11822]: Librespot-go daemon starting...
Apr 06 16:07:00 volumio go-librespot[11822]: time="2024-04-06T16:07:00Z" level=info msg="generated new device id: 81864965744e5876bca407123eb9d22cf8bef63c"
Apr 06 16:07:00 volumio go-librespot[11822]: time="2024-04-06T16:07:00Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:00 volumio go-librespot[11822]: time="2024-04-06T16:07:00Z" level=debug msg="obtained new client token: AADPwtBXFakb6uaObjQ2Jpae8ZvxKcmVF6NmUGUOkxFER+TAhXMSek69/+aXls1Ew1jJYeiYmi7eph7KJ4+camFHeTPZ+tuPzndwdLatL1E6mA8c5iVjCMfli+KEbPospMfIr5O9P+01U9X/rVCB9ROP6M7MAr0l5WQKZWbkpqP6n9nourSqk4iNaMvl8xZeOyfknXOT5yfUxwQnuzYrijAjWArp0xzhn5w/Tcob2VY6vdTHrFS8/Pb2dw31APc="
Apr 06 16:07:00 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:00 volumio go-librespot[11822]: time="2024-04-06T16:07:00Z" level=debug msg="new websocket client"
Apr 06 16:07:00 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:07:01 volumio go-librespot[11822]: time="2024-04-06T16:07:01Z" 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]"
Apr 06 16:07:01 volumio go-librespot[11822]: time="2024-04-06T16:07:01Z" level=debug msg="completed keyexchange"
Apr 06 16:07:01 volumio go-librespot[11822]: time="2024-04-06T16:07:01Z" level=debug msg="completed challenge"
Apr 06 16:07:01 volumio go-librespot[11822]: time="2024-04-06T16:07:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:01 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:07:03 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:07:03 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:03 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:07:03 volumio volumio[775]: (node:775) 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: 751)
Apr 06 16:07:04 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
Apr 06 16:07:04 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:04 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:07:04 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:07:04 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:07:04 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:04 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:04 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:07:04 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:04 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2265.
Apr 06 16:07:04 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:04 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:04 volumio go-librespot[11831]: Librespot-go daemon starting...
Apr 06 16:07:04 volumio go-librespot[11831]: time="2024-04-06T16:07:04Z" level=info msg="generated new device id: 30f0e99d4d7b6729c5f7ffc553036092e33376f3"
Apr 06 16:07:04 volumio go-librespot[11831]: time="2024-04-06T16:07:04Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:05 volumio go-librespot[11831]: time="2024-04-06T16:07:05Z" level=debug msg="obtained new client token: AACigCA7PfU7wOMmHRYMWd02QjhDaC8mF6yKNNSsPuZ+gMjmY98oT1y8mMpcwc9Lmc7Oys5IvE2PpTtzE/u632PPF2pBfV1M01+RcYGLF9fWym9rW2W2K41QQ9oOHMy40xcAzY1GU5+eQvAW1Onz6BAqAXnhZijd2BtkHTIYO51qVvnHkndES+NME8PfxKOrLrUFTPSCQfu0Fo2AqeSdUGR4LHu8l4VBPGbiwo8iFdf+qHSI/ZRTpYYKrstT"
Apr 06 16:07:05 volumio go-librespot[11831]: time="2024-04-06T16:07:05Z" 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]"
Apr 06 16:07:05 volumio go-librespot[11831]: time="2024-04-06T16:07:05Z" level=debug msg="completed keyexchange"
Apr 06 16:07:05 volumio go-librespot[11831]: time="2024-04-06T16:07:05Z" level=debug msg="completed challenge"
Apr 06 16:07:06 volumio go-librespot[11831]: time="2024-04-06T16:07:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:07 volumio volumio[775]: info: Retrieving Cloud Streaming UI
Apr 06 16:07:07 volumio volumio[775]: info: Getting Tidal Cloud Configuration
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:07 volumio volumio[775]: info: Getting Qobuz Cloud Configuration
Apr 06 16:07:07 volumio volumio[775]: info: Asking plugin for UI Config
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:07 volumio volumio[775]: info: Getting Spotify Cloud Configuration
Apr 06 16:07:07 volumio volumio[775]: info: Asking plugin for UI Config
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:07 volumio volumio[775]: info: Saving Spotify Acccount
Apr 06 16:07:07 volumio volumio[775]: info: Got Tidal Cloud Configuration
Apr 06 16:07:07 volumio volumio[775]: info: Got it
Apr 06 16:07:07 volumio volumio[775]: info: Got it
Apr 06 16:07:07 volumio volumio[775]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:07 volumio volumio[775]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 06 16:07:07 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Apr 06 16:07:07 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:07 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2266.
Apr 06 16:07:09 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:09 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:09 volumio go-librespot[11839]: Librespot-go daemon starting...
Apr 06 16:07:09 volumio go-librespot[11839]: time="2024-04-06T16:07:09Z" level=info msg="generated new device id: edb1e9958534ab0866197b493086c9e325f0933a"
Apr 06 16:07:09 volumio go-librespot[11839]: time="2024-04-06T16:07:09Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:09 volumio go-librespot[11839]: time="2024-04-06T16:07:09Z" level=debug msg="obtained new client token: AAAW6Glp0JIXbrnSrWPhuDVCh1aGGSMaHWvk0vH5i+GvpuMkYvvkMMGcGuvHcF1QAlgLUoUmV5wtPCjTbl+r+Cys65lE2zktkW23iUf5jo9C77L2yj0lWm4ZC3vEDMKZLx5rHUAZCfut3dtm/z0RRtXsKoG2ckOTK1aIs6g/MEZAvYAi/FvnCuItoIXjoXAq4zgpKVL+6w8oaY+6V363JxsXFrP6yTzUqCuDsZ4pUjPvQtjRibsvq7nHNdKv7Uw="
Apr 06 16:07:09 volumio go-librespot[11839]: time="2024-04-06T16:07:09Z" 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]"
Apr 06 16:07:09 volumio go-librespot[11839]: time="2024-04-06T16:07:09Z" level=debug msg="completed keyexchange"
Apr 06 16:07:10 volumio go-librespot[11839]: time="2024-04-06T16:07:10Z" level=debug msg="completed challenge"
Apr 06 16:07:10 volumio go-librespot[11839]: time="2024-04-06T16:07:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 06 16:07:10 volumio volumio[775]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Apr 06 16:07:10 volumio volumio[775]: info: Received Get System Version
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 06 16:07:10 volumio volumio[775]: info: Received Get System Info
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:07:10 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:10 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:10 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:07:10 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:10 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:11 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 06 16:07:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2267.
Apr 06 16:07:13 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:13 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:13 volumio go-librespot[11848]: Librespot-go daemon starting...
Apr 06 16:07:13 volumio go-librespot[11848]: time="2024-04-06T16:07:13Z" level=info msg="generated new device id: 3fea67cf0b9f2380ac25a81cb95f7f1f2c83614a"
Apr 06 16:07:13 volumio go-librespot[11848]: time="2024-04-06T16:07:13Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:13 volumio go-librespot[11848]: time="2024-04-06T16:07:13Z" level=debug msg="obtained new client token: AAC0wu3dy0U3fMSE2m5iVv7QxDt7HevrQzfaQMuANr4mkGVoeEsWeGrJ2/CifMuz0chamQ9wR0mteg1bVXvyyEK0iWAFF1RzphHZiKnn9/0xMku7qTN035+tRnyJUn0wdR0eQTOjT1pRqcmcjHsDaGfdUpF5S40g7aYuRiJsypzzNIIISOLV8RNVbp9MG4tBiOy5Xa+1r75rC5mxDFcBT9rCNL5WpkDYmnvyKJPBgfWSQESW5nprsXqXmBTky8I="
Apr 06 16:07:13 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 06 16:07:13 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 06 16:07:13 volumio volumio[775]: info: Discovery: Getting this device information
Apr 06 16:07:13 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:13 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:13 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 06 16:07:13 volumio go-librespot[11848]: time="2024-04-06T16:07:13Z" 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]"
Apr 06 16:07:13 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:13 volumio go-librespot[11848]: time="2024-04-06T16:07:13Z" level=debug msg="new websocket client"
Apr 06 16:07:13 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:07:13 volumio go-librespot[11848]: time="2024-04-06T16:07:13Z" level=debug msg="completed keyexchange"
Apr 06 16:07:14 volumio go-librespot[11848]: time="2024-04-06T16:07:14Z" level=debug msg="completed challenge"
Apr 06 16:07:14 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:14 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Apr 06 16:07:14 volumio go-librespot[11848]: time="2024-04-06T16:07:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:14 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:07:14 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Apr 06 16:07:14 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Apr 06 16:07:14 volumio volumio[775]: info: Received Get System Version
Apr 06 16:07:14 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 06 16:07:16 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:07:16 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:16 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:07:16 volumio volumio[775]: (node:775) 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: 752)
Apr 06 16:07:16 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
Apr 06 16:07:16 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:16 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:17 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:17 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2268.
Apr 06 16:07:17 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:17 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:17 volumio go-librespot[11870]: Librespot-go daemon starting...
Apr 06 16:07:17 volumio go-librespot[11870]: time="2024-04-06T16:07:17Z" level=info msg="generated new device id: b0d00d41a70a14928ce84134ee210dbd4af8b510"
Apr 06 16:07:17 volumio go-librespot[11870]: time="2024-04-06T16:07:17Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:17 volumio go-librespot[11870]: time="2024-04-06T16:07:17Z" level=debug msg="obtained new client token: AADREdYvNjEAX/wRrQ+sTTJ/k2qIoRxPNckPHzg4nAVw4xQtovpimmtX4mbYvvehhqXO5FSs9DlBZblVJZiPieWsfkvv92eEkdRFohXVinLhU1K0BKhlYzTARin2tY6gkoBhe9OQ6chpfwR/a08NGhcksU4YNPqfrgZgNYmP+oEeK11PP/JdQ3fdCH7LjoEB7zgsnU+TfaBcqTfWHnCDHzEMOlMDv/9JdqBsqGWWLc00I7oE4wzWsdog5xXgX+M="
Apr 06 16:07:18 volumio go-librespot[11870]: time="2024-04-06T16:07:18Z" 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]"
Apr 06 16:07:18 volumio go-librespot[11870]: time="2024-04-06T16:07:18Z" level=debug msg="completed keyexchange"
Apr 06 16:07:18 volumio go-librespot[11870]: time="2024-04-06T16:07:18Z" level=debug msg="completed challenge"
Apr 06 16:07:18 volumio go-librespot[11870]: time="2024-04-06T16:07:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:20 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:20 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:21 volumio volumio-remote-updater[564]: No test mode
Apr 06 16:07:21 volumio volumio-remote-updater[564]: No alpha test mode
Apr 06 16:07:21 volumio volumio[775]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Apr 06 16:07:21 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Apr 06 16:07:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2269.
Apr 06 16:07:21 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:21 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:21 volumio go-librespot[11880]: Librespot-go daemon starting...
Apr 06 16:07:21 volumio go-librespot[11880]: time="2024-04-06T16:07:21Z" level=info msg="generated new device id: e6afafcfdb1c3b61fb35eb250d0504e477dda5d3"
Apr 06 16:07:21 volumio go-librespot[11880]: time="2024-04-06T16:07:21Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:22 volumio go-librespot[11880]: time="2024-04-06T16:07:22Z" level=debug msg="obtained new client token: AACMw/mrRyVM4s2aradlBbJSeXLr0vA0qvcqNW+s4caNQFNifsuwgelAAW/HN3Rp5W8NVRYp49vyhkdFX4mlacMROIQFfDznWPZhF85sW7b44yDUlIAQ6/TKWOGp0oTQPKX6Q9FHe7NVKwrya9l1o/gRNIyLuAWSk9cv/PmohMf8PXmhP2SJ1sY3kgb5XhjmEmcBifusnrzjO+wVHdQSRRF3BTTDS+7RTu2Qfcx9QaEQhdoA4W1qwoC7NS/W"
Apr 06 16:07:22 volumio go-librespot[11880]: time="2024-04-06T16:07:22Z" 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]"
Apr 06 16:07:22 volumio go-librespot[11880]: time="2024-04-06T16:07:22Z" level=debug msg="completed keyexchange"
Apr 06 16:07:22 volumio volumio[775]: info: CoreCommandRouter::Close All Modals sent
Apr 06 16:07:22 volumio go-librespot[11880]: time="2024-04-06T16:07:22Z" level=debug msg="completed challenge"
Apr 06 16:07:22 volumio go-librespot[11880]: time="2024-04-06T16:07:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:23 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:23 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2270.
Apr 06 16:07:26 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:26 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:26 volumio go-librespot[11888]: Librespot-go daemon starting...
Apr 06 16:07:26 volumio go-librespot[11888]: time="2024-04-06T16:07:26Z" level=info msg="generated new device id: 0efac394cb2959734204bc704329ae152621f926"
Apr 06 16:07:26 volumio go-librespot[11888]: time="2024-04-06T16:07:26Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:26 volumio go-librespot[11888]: time="2024-04-06T16:07:26Z" level=debug msg="obtained new client token: AACCsBRg5bE1BzAmRk7L5FkzMBZfksp/3djfiCjsUaKT3TmCkGbSJjcfzFQwNNadmkaiP1NCS+4yNAl1GhQVZ8LQmAQqF81GGF7X3sUMIwxHQIiMNgrP94wpcgolBZcJo1BiAygpTbl/IgT2lO0ZsrNw58fVjoyM1keOGF5FCPKFckB5uHzCn68h5fn+Jzpl1U4oLMeIM7kiDs1jcVdEYkkzI0VDq3AL5F0XRnGOYkyEEJt2jYpqWQlnjoalGg0="
Apr 06 16:07:26 volumio go-librespot[11888]: time="2024-04-06T16:07:26Z" 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]"
Apr 06 16:07:26 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:26 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:07:26 volumio go-librespot[11888]: time="2024-04-06T16:07:26Z" level=debug msg="new websocket client"
Apr 06 16:07:26 volumio go-librespot[11888]: time="2024-04-06T16:07:26Z" level=debug msg="completed keyexchange"
Apr 06 16:07:27 volumio go-librespot[11888]: time="2024-04-06T16:07:27Z" level=debug msg="completed challenge"
Apr 06 16:07:27 volumio go-librespot[11888]: time="2024-04-06T16:07:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:27 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:07:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:29 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:07:29 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:29 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:07:29 volumio volumio[775]: (node:775) 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: 753)
Apr 06 16:07:29 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
Apr 06 16:07:29 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:29 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:30 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:30 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2271.
Apr 06 16:07:30 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:30 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:30 volumio go-librespot[11896]: Librespot-go daemon starting...
Apr 06 16:07:30 volumio go-librespot[11896]: time="2024-04-06T16:07:30Z" level=info msg="generated new device id: e0c5aaa998b517a46faeff520ccf9ea0b9768a0e"
Apr 06 16:07:30 volumio go-librespot[11896]: time="2024-04-06T16:07:30Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:30 volumio go-librespot[11896]: time="2024-04-06T16:07:30Z" level=debug msg="obtained new client token: AADms7syryPtMyIfboE6UwCzGc8/VSX8qI+zGqFYbxm3JSoAiUH9PEZ5WIC0Dtm/B7zhG6Ej1vM/3DKYYuXTMy+I8X94eUZgHME9LjR9b5YWkZFDsMX2+RyRVcdDgQAJmhzxZ4hbmxAapGcxkLz9GM15o5xExjfuoal7AE30E0B/uytMgxrP+IaVx/nWnjzfXLrwaPrubQadFWefqg/Dr4TxDSlIEVYI2LVJ1JVIIgKTlWff4uedwEn/NgZuqI0="
Apr 06 16:07:30 volumio go-librespot[11896]: time="2024-04-06T16:07:30Z" 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]"
Apr 06 16:07:30 volumio go-librespot[11896]: time="2024-04-06T16:07:30Z" level=debug msg="completed keyexchange"
Apr 06 16:07:31 volumio go-librespot[11896]: time="2024-04-06T16:07:31Z" level=debug msg="completed challenge"
Apr 06 16:07:31 volumio go-librespot[11896]: time="2024-04-06T16:07:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:33 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:33 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2272.
Apr 06 16:07:34 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:34 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:34 volumio go-librespot[11905]: Librespot-go daemon starting...
Apr 06 16:07:34 volumio go-librespot[11905]: time="2024-04-06T16:07:34Z" level=info msg="generated new device id: d7519512e7f95e7b796db91dc47c0bd334b9950b"
Apr 06 16:07:34 volumio go-librespot[11905]: time="2024-04-06T16:07:34Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:34 volumio go-librespot[11905]: time="2024-04-06T16:07:34Z" level=debug msg="obtained new client token: AABIdQ6whQ9QZNXUxsCHqG7E7Oz3DyoMzkJPxj4TidJxICNOQLYLAXhqZT84y0KjBJBZ+1sNgfDGdGlRFPd62EBNd+vA3aNQqRVgGMalS7bXF2Wo0CKvDIDRg3AsxO+poWMYLz4Axa78DycwmJzBJKLSXBdwCnfBTC8vIdBYuY3f4PVMD0E1wnlMfETPqZ+2XeK2ur+J6IlKJPYglz/mGBv5Myls7CKBkFYb6VhIbXPdbczd3d7YuBlnCx7Sdmw="
Apr 06 16:07:35 volumio go-librespot[11905]: time="2024-04-06T16:07:35Z" 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]"
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:35 volumio volumio[775]: info: Retrieving Cloud Streaming UI
Apr 06 16:07:35 volumio volumio[775]: info: Getting Tidal Cloud Configuration
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:35 volumio volumio[775]: info: Getting Qobuz Cloud Configuration
Apr 06 16:07:35 volumio volumio[775]: info: Asking plugin for UI Config
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:35 volumio volumio[775]: info: Getting Spotify Cloud Configuration
Apr 06 16:07:35 volumio volumio[775]: info: Asking plugin for UI Config
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:35 volumio volumio[775]: info: Saving Spotify Acccount
Apr 06 16:07:35 volumio volumio[775]: info: Got Tidal Cloud Configuration
Apr 06 16:07:35 volumio volumio[775]: info: Got it
Apr 06 16:07:35 volumio volumio[775]: info: Got it
Apr 06 16:07:35 volumio volumio[775]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 06 16:07:35 volumio volumio[775]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 06 16:07:35 volumio go-librespot[11905]: time="2024-04-06T16:07:35Z" level=debug msg="completed keyexchange"
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 06 16:07:35 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Apr 06 16:07:35 volumio go-librespot[11905]: time="2024-04-06T16:07:35Z" level=debug msg="completed challenge"
Apr 06 16:07:35 volumio go-librespot[11905]: time="2024-04-06T16:07:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:36 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:36 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2273.
Apr 06 16:07:38 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:38 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:38 volumio go-librespot[11913]: Librespot-go daemon starting...
Apr 06 16:07:38 volumio go-librespot[11913]: time="2024-04-06T16:07:38Z" level=info msg="generated new device id: 5e724a521882e572309282fd87100630cb675645"
Apr 06 16:07:38 volumio go-librespot[11913]: time="2024-04-06T16:07:38Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:39 volumio go-librespot[11913]: time="2024-04-06T16:07:39Z" level=debug msg="obtained new client token: AABORT/xo38Dil8cUa094PQlaq8N2QzWUywCaMODRbsHMXlayEO9V1+2UWvKV6wtipYlCtWlYJcZq39ikJ7llA5+3WLmEpqgmOW+CJM6IB8DA5ZT9v4BsgfF9e0lgaST8RNPGUEYRPYIqzzImtfhqZO0GgjJYXYnJ5Rd/nzVSjb94lMvBkTg5IWG0KE4H3nbvrayPfpm1TaAjt4M6rEnV33CiP2rrWZWsSEpHNbuM2nY3cfc9X8B7TkmPQMA"
Apr 06 16:07:39 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:39 volumio go-librespot[11913]: time="2024-04-06T16:07:39Z" level=debug msg="new websocket client"
Apr 06 16:07:39 volumio volumio[775]: info: Connection to go-librespot Websocket established
Apr 06 16:07:39 volumio go-librespot[11913]: time="2024-04-06T16:07:39Z" 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]"
Apr 06 16:07:39 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 06 16:07:39 volumio go-librespot[11913]: time="2024-04-06T16:07:39Z" level=debug msg="completed keyexchange"
Apr 06 16:07:39 volumio go-librespot[11913]: time="2024-04-06T16:07:39Z" level=debug msg="completed challenge"
Apr 06 16:07:39 volumio go-librespot[11913]: time="2024-04-06T16:07:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:39 volumio volumio[775]: info: Connection to go-librespot Websocket closed
Apr 06 16:07:42 volumio volumio[775]: info: Getting Spotify volume
Apr 06 16:07:42 volumio volumio[775]: (node:775) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:42 volumio volumio[775]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 06 16:07:42 volumio volumio[775]: (node:775) 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: 754)
Apr 06 16:07:42 volumio volumio[775]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9
Apr 06 16:07:42 volumio volumio[775]: info: CoreCommandRouter::volumioGetState
Apr 06 16:07:42 volumio volumio[775]: info: CorePlayQueue::getTrack 0
Apr 06 16:07:42 volumio volumio[775]: info: Initializing connection to go-librespot Websocket
Apr 06 16:07:42 volumio volumio[775]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 06 16:07:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 06 16:07:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2274.
Apr 06 16:07:43 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 06 16:07:43 volumio systemd[1]: Started go-librespot Daemon.
Apr 06 16:07:43 volumio go-librespot[11922]: Librespot-go daemon starting...
Apr 06 16:07:43 volumio go-librespot[11922]: time="2024-04-06T16:07:43Z" level=info msg="generated new device id: 54486e99462b00e4d81b1acdb26c697853d603f9"
Apr 06 16:07:43 volumio go-librespot[11922]: time="2024-04-06T16:07:43Z" level=debug msg="stored credentials found for radiopokopokito"
Apr 06 16:07:43 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 06 16:07:43 volumio go-librespot[11922]: time="2024-04-06T16:07:43Z" level=debug msg="obtained new client token: AADkTigtIVrH4Pxdn66V4tcrKw7J7YRJHgGZgVblV4WsJtZPpotPtMAgwBxakX5QhGOjYZ3/zRdltY7pPwxj6ZL6gUJW/lqq2T+ceJjJswlk6e1DkgpCORQX9sIYT0A/cd1+8mh9EaCs0JAA8wpiRjG+yz7Kyqz2JYI5JM8E4YVO1MeSrQWtH3zbym6TZ78XjU47ogTub+sh5uiQch9Yldw9H6AKlYr6SvBmx8CBo2PvqkuQK+YjzeZ7Au1HbJ0="
Apr 06 16:07:43 volumio go-librespot[11922]: time="2024-04-06T16:07:43Z" 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]"
Apr 06 16:07:43 volumio go-librespot[11922]: time="2024-04-06T16:07:43Z" level=debug msg="completed keyexchange"
Apr 06 16:07:44 volumio go-librespot[11922]: time="2024-04-06T16:07:44Z" level=debug msg="completed challenge"
Apr 06 16:07:44 volumio go-librespot[11922]: time="2024-04-06T16:07:44Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials"
Apr 06 16:07:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 06 16:07:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 06 16:07:44 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares
Apr 06 16:07:44 volumio volumio[775]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService
Apr 06 16:07:45 volumio volumio[775]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 06 16:07:45 volumio volumio[775]: Error: getaddrinfo -3007
Apr 06 16:07:45 volumio volumio[775]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11)
Apr 06 16:07:45 volumio volumio[775]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10)
Apr 06 16:07:45 volumio volumio[775]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) {
Apr 06 16:07:45 volumio volumio[775]: code: -3007,
Apr 06 16:07:45 volumio volumio[775]: errno: -3007,
Apr 06 16:07:45 volumio volumio[775]: syscall: 'getaddrinfo'
Apr 06 16:07:45 volumio volumio[775]: }
Apr 06 16:07:45 volumio volumio[775]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 06 16:07:45 volumio sudo[11941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-06 16:06
Apr 06 16:07:45 volumio sudo[11941]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET"
VOLUMIO_VERSION="3.631"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"