-- Logs begin at Thu 2024-10-03 07:07:03 CEST, end at Thu 2024-10-03 21:12:57 CEST. --
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="fetched first chunk of 21, total size is 10834260 bytes" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:00 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=info msg="loaded track \"Lupus Aurora\" (paused: false, position: 0ms, duration: 251513ms, prefetched: false)" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=trace msg="scheduling prefetch in 221s"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=trace msg="emitting websocket event: metadata"
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","name":"Lupus Aurora","artist_names":["Cytotoxin"],"album_name":"Nuklearth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","position":0,"duration":251513,"release_date":"year:2020 month:8 day:21","track_number":2,"disc_number":1}}
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","name":"Lupus Aurora","artist_names":["Cytotoxin"],"album_name":"Nuklearth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","position":0,"duration":251513,"release_date":"year:2020 month:8 day:21","track_number":2,"disc_number":1}}
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=trace msg="emitting websocket event: paused"
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","play_origin":"go-librespot"}}
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: verbose: CURRENT POSITION 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","play_origin":"go-librespot"}}
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: verbose: CURRENT POSITION 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=trace msg="emitting websocket event: playing"
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","play_origin":"go-librespot"}}
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: verbose: CURRENT POSITION 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","play_origin":"go-librespot"}}
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: verbose: CURRENT POSITION 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:00 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: info: [LastFM] Current track has sufficient metadata: title (Lupus Aurora) and artist (Cytotoxin) passed on explicitly
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:00 volumio volumio[1189]: [LastFM] updated "now playing" failed: {
Oct 03 21:11:00 volumio volumio[1189]: success: false,
Oct 03 21:11:00 volumio volumio[1189]: error: 'Invalid parameters - Your request is missing a required parameter'
Oct 03 21:11:00 volumio volumio[1189]: }
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: verbose: CURRENT POSITION 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:00 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d00001e025e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","seek":0,"duration":251,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:00 volumio volumio[1189]: verbose: CURRENT POSITION 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:00 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:00 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:00 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:00 volumio volumio[1189]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Lupus Aurora","url":"https://www.last.fm/music/Cytotoxin/_/Lupus+Aurora","duration":"251000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"7067","playcount":"40781","artist":{"name":"Cytotoxin","mbid":"640659f0-bcd9-4600-950c-a2958420a680","url":"https://www.last.fm/music/Cytotoxin"},"album":{"artist":"Cytotoxin","title":"Lupus Aurora","url":"https://www.last.fm/music/Cytotoxin/Lupus+Aurora","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/0699f391914393ba704b4669c91a56e6.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/0699f391914393ba704b4669c91a56e6.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/0699f391914393ba704b4669c91a56e6.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/0699f391914393ba704b4669c91a56e6.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":""}}
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:00 volumio go-librespot[20816]: time="2024-10-03T21:11:00+02:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:04 volumio volumio[1189]: info: CoreCommandRouter::volumioGetState
Oct 03 21:11:04 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:11 volumio go-librespot[20816]: time="2024-10-03T21:11:11+02:00" level=debug msg="fetched chunk 4/20, size: 524288" uri="spotify:track:16MIqM8waXb51nI94J3iAO"
Oct 03 21:11:14 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::ClearQueue
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::stPlaybackTimer
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::serviceStop
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 34
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::serviceStop
Oct 03 21:11:14 volumio volumio[1189]: info: Spotify Stop
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: SPOTIFY STOP
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: {"status":"play","position":34,"title":"Lupus Aurora","artist":"Cytotoxin","album":"Nuklearth","albumart":"https://i.scdn.co/image/ab67616d0000b2735e5e5955dac9c0168d17eaeb","uri":"spotify:track:16MIqM8waXb51nI94J3iAO","trackType":"spotify","codec":"ogg","seek":0,"duration":251,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":29,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Oct 03 21:11:14 volumio volumio[1189]: info: Sending Spotify command to local API: /player/pause
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::clearPlayQueue
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::addQueueItems
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::addQueueItems
Oct 03 21:11:14 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7dfyknuaAWlEdprIhXPuml
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7dfyknuaAWlEdprIhXPuml
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0kRKOryyYTiB4TdruvZFno
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0kRKOryyYTiB4TdruvZFno
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0FFI8kPrtI1bWTLyOsLxzi
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0FFI8kPrtI1bWTLyOsLxzi
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5WGvXmLt6acluR7TfhlHUH
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:5WGvXmLt6acluR7TfhlHUH
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7dU9Z24yR9AKuS9cAe2Tj7
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7dU9Z24yR9AKuS9cAe2Tj7
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:6e01NBK5kHDf0emnALYvuH
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:6e01NBK5kHDf0emnALYvuH
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7pvVBes4xd47RXSNJxDmIu
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7pvVBes4xd47RXSNJxDmIu
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:375jkxSs2eufFGqRBJTdhQ
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:375jkxSs2eufFGqRBJTdhQ
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:75rkqAP4omxXp9WaAlwcZz
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:75rkqAP4omxXp9WaAlwcZz
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2KvUQpIGMypbAPJlZDR1aM
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:2KvUQpIGMypbAPJlZDR1aM
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5jhBXMPyxIHi9hRtNr8wme
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:5jhBXMPyxIHi9hRtNr8wme
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:352Xb6jVxDanrtT7hQyJDH
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:352Xb6jVxDanrtT7hQyJDH
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1rFGvIgrnnKHfNk9OWFQHd
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1rFGvIgrnnKHfNk9OWFQHd
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Td8ngT20cgpCDmDQb8yGs
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0Td8ngT20cgpCDmDQb8yGs
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Z5ZyJZI5p3UvPahYe2Hpj
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0Z5ZyJZI5p3UvPahYe2Hpj
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:6w5WxEMtYQimKeucZS5izb
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:6w5WxEMtYQimKeucZS5izb
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4dmtHH6ICLG2dVcCOdl7xa
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4dmtHH6ICLG2dVcCOdl7xa
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5TISOiwexSROBtd0zf0tAp
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:5TISOiwexSROBtd0zf0tAp
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0PeNoUIHVHp0XQBSK640TP
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0PeNoUIHVHp0XQBSK640TP
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5CpAAbNdJ5CCyryja611TF
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:5CpAAbNdJ5CCyryja611TF
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3iZOVTPjyUEq9f5HsUQCj7
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3iZOVTPjyUEq9f5HsUQCj7
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1D3CA2MbScCrjOY6RpAa1U
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1D3CA2MbScCrjOY6RpAa1U
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0cuz31RlVI5Zz1371mgm7w
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0cuz31RlVI5Zz1371mgm7w
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4RmEemZjQl0BVZbWDcPoYu
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4RmEemZjQl0BVZbWDcPoYu
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1U0aOuzMlroJj5ratmAUiU
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1U0aOuzMlroJj5ratmAUiU
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3az8b1yUBQ2JJMgRP0hXwQ
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3az8b1yUBQ2JJMgRP0hXwQ
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:57MQ7KgMW2CRbyrWL7CH2W
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:57MQ7KgMW2CRbyrWL7CH2W
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4c0UaGIbiDKUOQ9nPeWvVs
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4c0UaGIbiDKUOQ9nPeWvVs
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7DHISgo9Uu4sgGrntWv6Hw
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7DHISgo9Uu4sgGrntWv6Hw
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3ywnVanY59SrPxNhhSUrN8
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3ywnVanY59SrPxNhhSUrN8
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4DpSEMsOSibGpgVEmI5G5B
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4DpSEMsOSibGpgVEmI5G5B
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5y25DV4hGYUizcnAH1kFgM
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:5y25DV4hGYUizcnAH1kFgM
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:45QRBDrfLXVvJn2VeGPQCn
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:45QRBDrfLXVvJn2VeGPQCn
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:546OjMyW4EJhqveZmqtgsQ
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:546OjMyW4EJhqveZmqtgsQ
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:16MIqM8waXb51nI94J3iAO
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:16MIqM8waXb51nI94J3iAO
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1pDaIv4kERYDqeCzYDpZ80
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1pDaIv4kERYDqeCzYDpZ80
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7pUBBayxQ3YaKrVSurhjG4
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7pUBBayxQ3YaKrVSurhjG4
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:22jfmM32Om1nFXPmJnxDcs
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:22jfmM32Om1nFXPmJnxDcs
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:75S0mJv5bWWO6kJ2BvPgpK
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:75S0mJv5bWWO6kJ2BvPgpK
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:58zypYCPl2jwCI63sg8J4W
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:58zypYCPl2jwCI63sg8J4W
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3GeFIptUSLYybmyhkPVjjf
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3GeFIptUSLYybmyhkPVjjf
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2QVXnSWUAPNGZ1GuV6rAnP
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:2QVXnSWUAPNGZ1GuV6rAnP
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:69EhXRbe17FYLqqdpB0jnC
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:69EhXRbe17FYLqqdpB0jnC
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:25UJzWEeCK3wGslX8iLrt2
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:25UJzWEeCK3wGslX8iLrt2
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7CMkMpcVK6MofjXM8vSAnd
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7CMkMpcVK6MofjXM8vSAnd
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3D6ZPZrFk2CHZCJ2STxHW7
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3D6ZPZrFk2CHZCJ2STxHW7
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4s7uHuYDYp0bACtrsGcXTD
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4s7uHuYDYp0bACtrsGcXTD
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5bA0ZDc7qg5R1qxINkIB2D
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:5bA0ZDc7qg5R1qxINkIB2D
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4Hi1Wnq7pq3T8XJKBhmCMP
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4Hi1Wnq7pq3T8XJKBhmCMP
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Xm0dF2MmJctbAi5iz64XL
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0Xm0dF2MmJctbAi5iz64XL
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4Qx8xQSOhYMtIDh5liCDpF
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4Qx8xQSOhYMtIDh5liCDpF
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3G1QJ5yuNw385SULJFEjzJ
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3G1QJ5yuNw385SULJFEjzJ
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3SxwydxyvGo3Um32X7vTEY
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:3SxwydxyvGo3Um32X7vTEY
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4KLup5onhhZjysHCT89upc
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:4KLup5onhhZjysHCT89upc
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1yTk2dEtxvvLTisREsDyVe
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1yTk2dEtxvvLTisREsDyVe
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1zXTJp4mMwu2y69LajfzFK
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1zXTJp4mMwu2y69LajfzFK
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:34sbAfcmrPhJqpszzwMyhv
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:34sbAfcmrPhJqpszzwMyhv
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:74UuxmgXCk9lE6GjDJRLkH
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:74UuxmgXCk9lE6GjDJRLkH
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1dEtXRznHGSyWNwmpmKXWn
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1dEtXRznHGSyWNwmpmKXWn
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1AjSrQPfK7PlyE6HPAidXh
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:1AjSrQPfK7PlyE6HPAidXh
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:774kFk9YCPyTYR7sSIDqum
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:774kFk9YCPyTYR7sSIDqum
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:67ysFzoO0jw9lX700WCE2j
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:67ysFzoO0jw9lX700WCE2j
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7Bn3fVcSIpoTUwDIzWom0Q
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:7Bn3fVcSIpoTUwDIzWom0Q
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2wu3hOKDKAO0TgC78RmSvZ
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:2wu3hOKDKAO0TgC78RmSvZ
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2c3XylA6lP5W2qHiPYuV2W
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:2c3XylA6lP5W2qHiPYuV2W
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0EDi8nGDIcZ0PmvoS9pOVC
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:0EDi8nGDIcZ0PmvoS9pOVC
Oct 03 21:11:14 volumio volumio[1189]: info: Adding Item to queue: spotify:track:49ZO03I7BV9oLHbWbnlJIg
Oct 03 21:11:14 volumio volumio[1189]: info: Using cached record of: spotify:track:49ZO03I7BV9oLHbWbnlJIg
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioPlay
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::play index 36
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::play index undefined
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:14 volumio volumio[1189]: info: [1727982674751] ControllerSpotify::clearAddPlayTrack
Oct 03 21:11:14 volumio volumio[1189]: info: Sending Spotify command with payload to local API: /player/play
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:14 volumio go-librespot[20816]: time="2024-10-03T21:11:14+02:00" level=debug msg="pause track at 14691ms"
Oct 03 21:11:14 volumio go-librespot[20816]: time="2024-10-03T21:11:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:14 volumio go-librespot[20816]: time="2024-10-03T21:11:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:14 volumio go-librespot[20816]: time="2024-10-03T21:11:14+02:00" level=trace msg="emitting websocket event: paused"
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","play_origin":"go-librespot"}}
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:14 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:14 volumio volumio[1189]: verbose: CURRENT POSITION 36
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:16MIqM8waXb51nI94J3iAO","play_origin":"go-librespot"}}
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:14 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:14 volumio volumio[1189]: verbose: CURRENT POSITION 36
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:14 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:14 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:14 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:14 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="resolved context of track" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=trace msg="emitting websocket event: will_play"
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","play_origin":"go-librespot"}}
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="selected format OGG_VORBIS_320 (8f36669500ec8799994ef8368147f4f921f9385c)" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="requested aes key for file 8f36669500ec8799994ef8368147f4f921f9385c, gid: 7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="fetched first chunk of 19, total size is 9469444 bytes" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=info msg="loaded track \"Stoneage\" (paused: false, position: 0ms, duration: 202000ms, prefetched: false)" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=trace msg="scheduling prefetch in 172s"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=trace msg="emitting websocket event: metadata"
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","name":"Stoneage","artist_names":["Korpse"],"album_name":"Unethical","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","position":0,"duration":202000,"release_date":"year:2016 month:3 day:18","track_number":5,"disc_number":1}}
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","name":"Stoneage","artist_names":["Korpse"],"album_name":"Unethical","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","position":0,"duration":202000,"release_date":"year:2016 month:3 day:18","track_number":5,"disc_number":1}}
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:15 volumio go-librespot[20816]: time="2024-10-03T21:11:15+02:00" level=trace msg="emitting websocket event: playing"
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","play_origin":"go-librespot"}}
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:15 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:15 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:15 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:15 volumio volumio[1189]: verbose: CURRENT POSITION 36
Oct 03 21:11:15 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:15 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","play_origin":"go-librespot"}}
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:15 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:15 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:15 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:15 volumio volumio[1189]: verbose: CURRENT POSITION 36
Oct 03 21:11:15 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:15 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:15 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:15 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:15 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:15 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:15 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:15 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:15 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:15 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:15 volumio volumio[1189]: info: [LastFM] Current track has sufficient metadata: title (Stoneage) and artist (Korpse) passed on explicitly
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:15 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:16 volumio volumio[1189]: [LastFM] updated "now playing" failed: {
Oct 03 21:11:16 volumio volumio[1189]: success: false,
Oct 03 21:11:16 volumio volumio[1189]: error: 'Invalid parameters - Your request is missing a required parameter'
Oct 03 21:11:16 volumio volumio[1189]: }
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:16 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:16 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:16 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:16 volumio volumio[1189]: verbose: CURRENT POSITION 36
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:16 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:16 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:16 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:16 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:16 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:16 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:16 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:16 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d00001e0225c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","seek":0,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:16 volumio volumio[1189]: verbose: CURRENT POSITION 36
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:16 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:16 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:16 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:16 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:16 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:16 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:16 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:16 volumio volumio[1189]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Stoneage","url":"https://www.last.fm/music/Korpse/_/Stoneage","duration":"202000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"2028","playcount":"8322","artist":{"name":"Korpse","mbid":"077824ee-0ed2-483a-a288-3897aaeedde7","url":"https://www.last.fm/music/Korpse"},"album":{"artist":"Korpse","title":"Unethical","url":"https://www.last.fm/music/Korpse/Unethical","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/0ab1d104442c1b5b22a68caaf24719df.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/0ab1d104442c1b5b22a68caaf24719df.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/0ab1d104442c1b5b22a68caaf24719df.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/0ab1d104442c1b5b22a68caaf24719df.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":""}}
Oct 03 21:11:18 volumio volumio[1189]: info: CoreCommandRouter::volumioGetState
Oct 03 21:11:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:26 volumio go-librespot[20816]: time="2024-10-03T21:11:26+02:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:7pUBBayxQ3YaKrVSurhjG4"
Oct 03 21:11:35 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::ClearQueue
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::stPlaybackTimer
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::serviceStop
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 36
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::serviceStop
Oct 03 21:11:35 volumio volumio[1189]: info: Spotify Stop
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: SPOTIFY STOP
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: {"status":"play","position":36,"title":"Stoneage","artist":"Korpse","album":"Unethical","albumart":"https://i.scdn.co/image/ab67616d0000b27325c9406d31f0b2904478580a","uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","trackType":"spotify","codec":"ogg","seek":0,"duration":202,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":29,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Oct 03 21:11:35 volumio volumio[1189]: info: Sending Spotify command to local API: /player/pause
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::clearPlayQueue
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::addQueueItems
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::addQueueItems
Oct 03 21:11:35 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7dfyknuaAWlEdprIhXPuml
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7dfyknuaAWlEdprIhXPuml
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0kRKOryyYTiB4TdruvZFno
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0kRKOryyYTiB4TdruvZFno
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0FFI8kPrtI1bWTLyOsLxzi
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0FFI8kPrtI1bWTLyOsLxzi
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5WGvXmLt6acluR7TfhlHUH
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:5WGvXmLt6acluR7TfhlHUH
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7dU9Z24yR9AKuS9cAe2Tj7
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7dU9Z24yR9AKuS9cAe2Tj7
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:6e01NBK5kHDf0emnALYvuH
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:6e01NBK5kHDf0emnALYvuH
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7pvVBes4xd47RXSNJxDmIu
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7pvVBes4xd47RXSNJxDmIu
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:375jkxSs2eufFGqRBJTdhQ
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:375jkxSs2eufFGqRBJTdhQ
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:75rkqAP4omxXp9WaAlwcZz
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:75rkqAP4omxXp9WaAlwcZz
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2KvUQpIGMypbAPJlZDR1aM
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:2KvUQpIGMypbAPJlZDR1aM
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5jhBXMPyxIHi9hRtNr8wme
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:5jhBXMPyxIHi9hRtNr8wme
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:352Xb6jVxDanrtT7hQyJDH
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:352Xb6jVxDanrtT7hQyJDH
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1rFGvIgrnnKHfNk9OWFQHd
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1rFGvIgrnnKHfNk9OWFQHd
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Td8ngT20cgpCDmDQb8yGs
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0Td8ngT20cgpCDmDQb8yGs
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Z5ZyJZI5p3UvPahYe2Hpj
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0Z5ZyJZI5p3UvPahYe2Hpj
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:6w5WxEMtYQimKeucZS5izb
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:6w5WxEMtYQimKeucZS5izb
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4dmtHH6ICLG2dVcCOdl7xa
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4dmtHH6ICLG2dVcCOdl7xa
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5TISOiwexSROBtd0zf0tAp
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:5TISOiwexSROBtd0zf0tAp
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0PeNoUIHVHp0XQBSK640TP
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0PeNoUIHVHp0XQBSK640TP
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5CpAAbNdJ5CCyryja611TF
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:5CpAAbNdJ5CCyryja611TF
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3iZOVTPjyUEq9f5HsUQCj7
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3iZOVTPjyUEq9f5HsUQCj7
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1D3CA2MbScCrjOY6RpAa1U
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1D3CA2MbScCrjOY6RpAa1U
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0cuz31RlVI5Zz1371mgm7w
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0cuz31RlVI5Zz1371mgm7w
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4RmEemZjQl0BVZbWDcPoYu
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4RmEemZjQl0BVZbWDcPoYu
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1U0aOuzMlroJj5ratmAUiU
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1U0aOuzMlroJj5ratmAUiU
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3az8b1yUBQ2JJMgRP0hXwQ
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3az8b1yUBQ2JJMgRP0hXwQ
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:57MQ7KgMW2CRbyrWL7CH2W
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:57MQ7KgMW2CRbyrWL7CH2W
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4c0UaGIbiDKUOQ9nPeWvVs
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4c0UaGIbiDKUOQ9nPeWvVs
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7DHISgo9Uu4sgGrntWv6Hw
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7DHISgo9Uu4sgGrntWv6Hw
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3ywnVanY59SrPxNhhSUrN8
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3ywnVanY59SrPxNhhSUrN8
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4DpSEMsOSibGpgVEmI5G5B
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4DpSEMsOSibGpgVEmI5G5B
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5y25DV4hGYUizcnAH1kFgM
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:5y25DV4hGYUizcnAH1kFgM
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:45QRBDrfLXVvJn2VeGPQCn
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:45QRBDrfLXVvJn2VeGPQCn
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:546OjMyW4EJhqveZmqtgsQ
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:546OjMyW4EJhqveZmqtgsQ
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:16MIqM8waXb51nI94J3iAO
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:16MIqM8waXb51nI94J3iAO
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1pDaIv4kERYDqeCzYDpZ80
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1pDaIv4kERYDqeCzYDpZ80
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7pUBBayxQ3YaKrVSurhjG4
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7pUBBayxQ3YaKrVSurhjG4
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:22jfmM32Om1nFXPmJnxDcs
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:22jfmM32Om1nFXPmJnxDcs
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:75S0mJv5bWWO6kJ2BvPgpK
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:75S0mJv5bWWO6kJ2BvPgpK
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:58zypYCPl2jwCI63sg8J4W
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:58zypYCPl2jwCI63sg8J4W
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3GeFIptUSLYybmyhkPVjjf
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3GeFIptUSLYybmyhkPVjjf
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2QVXnSWUAPNGZ1GuV6rAnP
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:2QVXnSWUAPNGZ1GuV6rAnP
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:69EhXRbe17FYLqqdpB0jnC
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:69EhXRbe17FYLqqdpB0jnC
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:25UJzWEeCK3wGslX8iLrt2
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:25UJzWEeCK3wGslX8iLrt2
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7CMkMpcVK6MofjXM8vSAnd
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7CMkMpcVK6MofjXM8vSAnd
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3D6ZPZrFk2CHZCJ2STxHW7
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3D6ZPZrFk2CHZCJ2STxHW7
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4s7uHuYDYp0bACtrsGcXTD
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4s7uHuYDYp0bACtrsGcXTD
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5bA0ZDc7qg5R1qxINkIB2D
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:5bA0ZDc7qg5R1qxINkIB2D
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4Hi1Wnq7pq3T8XJKBhmCMP
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4Hi1Wnq7pq3T8XJKBhmCMP
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Xm0dF2MmJctbAi5iz64XL
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0Xm0dF2MmJctbAi5iz64XL
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4Qx8xQSOhYMtIDh5liCDpF
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4Qx8xQSOhYMtIDh5liCDpF
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3G1QJ5yuNw385SULJFEjzJ
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3G1QJ5yuNw385SULJFEjzJ
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3SxwydxyvGo3Um32X7vTEY
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:3SxwydxyvGo3Um32X7vTEY
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4KLup5onhhZjysHCT89upc
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:4KLup5onhhZjysHCT89upc
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1yTk2dEtxvvLTisREsDyVe
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1yTk2dEtxvvLTisREsDyVe
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1zXTJp4mMwu2y69LajfzFK
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1zXTJp4mMwu2y69LajfzFK
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:34sbAfcmrPhJqpszzwMyhv
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:34sbAfcmrPhJqpszzwMyhv
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:74UuxmgXCk9lE6GjDJRLkH
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:74UuxmgXCk9lE6GjDJRLkH
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1dEtXRznHGSyWNwmpmKXWn
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1dEtXRznHGSyWNwmpmKXWn
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1AjSrQPfK7PlyE6HPAidXh
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:1AjSrQPfK7PlyE6HPAidXh
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:774kFk9YCPyTYR7sSIDqum
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:774kFk9YCPyTYR7sSIDqum
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:67ysFzoO0jw9lX700WCE2j
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:67ysFzoO0jw9lX700WCE2j
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7Bn3fVcSIpoTUwDIzWom0Q
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:7Bn3fVcSIpoTUwDIzWom0Q
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2wu3hOKDKAO0TgC78RmSvZ
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:2wu3hOKDKAO0TgC78RmSvZ
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2c3XylA6lP5W2qHiPYuV2W
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:2c3XylA6lP5W2qHiPYuV2W
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0EDi8nGDIcZ0PmvoS9pOVC
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:0EDi8nGDIcZ0PmvoS9pOVC
Oct 03 21:11:35 volumio volumio[1189]: info: Adding Item to queue: spotify:track:49ZO03I7BV9oLHbWbnlJIg
Oct 03 21:11:35 volumio volumio[1189]: info: Using cached record of: spotify:track:49ZO03I7BV9oLHbWbnlJIg
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioPlay
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::play index 42
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::play index undefined
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:35 volumio volumio[1189]: info: [1727982695363] ControllerSpotify::clearAddPlayTrack
Oct 03 21:11:35 volumio volumio[1189]: info: Sending Spotify command with payload to local API: /player/play
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="pause track at 19896ms"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=trace msg="emitting websocket event: paused"
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","play_origin":"go-librespot"}}
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:35 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:35 volumio volumio[1189]: verbose: CURRENT POSITION 42
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7pUBBayxQ3YaKrVSurhjG4","play_origin":"go-librespot"}}
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:35 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:35 volumio volumio[1189]: verbose: CURRENT POSITION 42
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:35 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:35 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:35 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="resolved context of track" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=trace msg="emitting websocket event: will_play"
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","play_origin":"go-librespot"}}
Oct 03 21:11:35 volumio volumio[1189]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","play_origin":"go-librespot"}}
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="selected format OGG_VORBIS_320 (ab5a74745e4ac089edd5af63ed08702b5963ff19)" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="requested aes key for file ab5a74745e4ac089edd5af63ed08702b5963ff19, gid: 69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=debug msg="fetched first chunk of 20, total size is 10092784 bytes" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio go-librespot[20816]: time="2024-10-03T21:11:35+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:35 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=info msg="loaded track \"Dissected By Righteousness\" (paused: false, position: 1ms, duration: 220960ms, prefetched: false)" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=trace msg="scheduling prefetch in 191s"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=trace msg="emitting websocket event: metadata"
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","name":"Dissected By Righteousness","artist_names":["Pathology"],"album_name":"Awaken To The Suffering","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","position":1,"duration":220960,"release_date":"year:2011 month:9 day:13","track_number":1,"disc_number":1}}
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","name":"Dissected By Righteousness","artist_names":["Pathology"],"album_name":"Awaken To The Suffering","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","position":1,"duration":220960,"release_date":"year:2011 month:9 day:13","track_number":1,"disc_number":1}}
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:36 volumio go-librespot[20816]: time="2024-10-03T21:11:36+02:00" level=trace msg="emitting websocket event: playing"
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","play_origin":"go-librespot"}}
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:36 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:36 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:36 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:36 volumio volumio[1189]: verbose: CURRENT POSITION 42
Oct 03 21:11:36 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:36 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","play_origin":"go-librespot"}}
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:36 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:36 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:36 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:36 volumio volumio[1189]: verbose: CURRENT POSITION 42
Oct 03 21:11:36 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:36 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:36 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:36 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:36 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:36 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:36 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:36 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:36 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:36 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:36 volumio volumio[1189]: info: [LastFM] Current track has sufficient metadata: title (Dissected By Righteousness) and artist (Pathology) passed on explicitly
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:36 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:36 volumio volumio[1189]: [LastFM] updated "now playing" failed: {
Oct 03 21:11:36 volumio volumio[1189]: success: false,
Oct 03 21:11:36 volumio volumio[1189]: error: 'Invalid parameters - Your request is missing a required parameter'
Oct 03 21:11:36 volumio volumio[1189]: }
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:37 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:37 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:37 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:37 volumio volumio[1189]: verbose: CURRENT POSITION 42
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:37 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:37 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:37 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:37 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:37 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:37 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:37 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:37 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d00001e02e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","seek":1,"duration":220,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:37 volumio volumio[1189]: verbose: CURRENT POSITION 42
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:37 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:37 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:37 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:37 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:37 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:37 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:37 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:38 volumio volumio[1189]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Dissected By Righteousness","mbid":"32e5c9f6-ad5e-4c68-b46d-aa83b37bd6ae","url":"https://www.last.fm/music/Pathology/_/Dissected+By+Righteousness","duration":"220000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"8507","playcount":"39119","artist":{"name":"Pathology","mbid":"50feb379-8266-4efa-9707-2a4acb2b6b43","url":"https://www.last.fm/music/Pathology"},"album":{"@":{"position":"1"},"artist":"Pathology","title":"Awaken To The Suffering","mbid":"91b2f1fa-0705-4cef-ab51-b7402104fe8e","url":"https://www.last.fm/music/Pathology/Awaken+To+The+Suffering","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/b0667d9793934997947d9580ec565cd4.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/b0667d9793934997947d9580ec565cd4.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/b0667d9793934997947d9580ec565cd4.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/b0667d9793934997947d9580ec565cd4.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":{"tag":[{"name":"Brutal Death Metal","url":"https://www.last.fm/tag/Brutal+Death+Metal"},{"name":"political","url":"https://www.last.fm/tag/political"},{"name":"death metal","url":"https://www.last.fm/tag/death+metal"},{"name":"goregrind","url":"https://www.last.fm/tag/goregrind"},{"name":"deathgrind","url":"https://www.last.fm/tag/deathgrind"}]}}}
Oct 03 21:11:44 volumio volumio[1189]: info: CoreCommandRouter::volumioGetState
Oct 03 21:11:44 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:46 volumio go-librespot[20816]: time="2024-10-03T21:11:46+02:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:69EhXRbe17FYLqqdpB0jnC"
Oct 03 21:11:51 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::ClearQueue
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::stPlaybackTimer
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::serviceStop
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 42
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::serviceStop
Oct 03 21:11:51 volumio volumio[1189]: info: Spotify Stop
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: SPOTIFY STOP
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: {"status":"play","position":42,"title":"Dissected By Righteousness","artist":"Pathology","album":"Awaken To The Suffering","albumart":"https://i.scdn.co/image/ab67616d0000b273e1349c91a4104360ba66b01d","uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","trackType":"spotify","codec":"ogg","seek":1,"duration":220,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":29,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Oct 03 21:11:51 volumio volumio[1189]: info: Sending Spotify command to local API: /player/pause
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::clearPlayQueue
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::addQueueItems
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::addQueueItems
Oct 03 21:11:51 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7dfyknuaAWlEdprIhXPuml
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7dfyknuaAWlEdprIhXPuml
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0kRKOryyYTiB4TdruvZFno
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0kRKOryyYTiB4TdruvZFno
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0FFI8kPrtI1bWTLyOsLxzi
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0FFI8kPrtI1bWTLyOsLxzi
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5WGvXmLt6acluR7TfhlHUH
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:5WGvXmLt6acluR7TfhlHUH
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7dU9Z24yR9AKuS9cAe2Tj7
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7dU9Z24yR9AKuS9cAe2Tj7
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:6e01NBK5kHDf0emnALYvuH
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:6e01NBK5kHDf0emnALYvuH
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7pvVBes4xd47RXSNJxDmIu
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7pvVBes4xd47RXSNJxDmIu
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:375jkxSs2eufFGqRBJTdhQ
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:375jkxSs2eufFGqRBJTdhQ
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:75rkqAP4omxXp9WaAlwcZz
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:75rkqAP4omxXp9WaAlwcZz
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2KvUQpIGMypbAPJlZDR1aM
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:2KvUQpIGMypbAPJlZDR1aM
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5jhBXMPyxIHi9hRtNr8wme
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:5jhBXMPyxIHi9hRtNr8wme
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:352Xb6jVxDanrtT7hQyJDH
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:352Xb6jVxDanrtT7hQyJDH
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1rFGvIgrnnKHfNk9OWFQHd
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1rFGvIgrnnKHfNk9OWFQHd
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Td8ngT20cgpCDmDQb8yGs
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0Td8ngT20cgpCDmDQb8yGs
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Z5ZyJZI5p3UvPahYe2Hpj
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0Z5ZyJZI5p3UvPahYe2Hpj
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:6w5WxEMtYQimKeucZS5izb
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:6w5WxEMtYQimKeucZS5izb
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4dmtHH6ICLG2dVcCOdl7xa
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4dmtHH6ICLG2dVcCOdl7xa
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5TISOiwexSROBtd0zf0tAp
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:5TISOiwexSROBtd0zf0tAp
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0PeNoUIHVHp0XQBSK640TP
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0PeNoUIHVHp0XQBSK640TP
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5CpAAbNdJ5CCyryja611TF
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:5CpAAbNdJ5CCyryja611TF
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3iZOVTPjyUEq9f5HsUQCj7
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3iZOVTPjyUEq9f5HsUQCj7
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1D3CA2MbScCrjOY6RpAa1U
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1D3CA2MbScCrjOY6RpAa1U
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0cuz31RlVI5Zz1371mgm7w
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0cuz31RlVI5Zz1371mgm7w
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4RmEemZjQl0BVZbWDcPoYu
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4RmEemZjQl0BVZbWDcPoYu
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1U0aOuzMlroJj5ratmAUiU
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1U0aOuzMlroJj5ratmAUiU
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3az8b1yUBQ2JJMgRP0hXwQ
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3az8b1yUBQ2JJMgRP0hXwQ
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:57MQ7KgMW2CRbyrWL7CH2W
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:57MQ7KgMW2CRbyrWL7CH2W
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4c0UaGIbiDKUOQ9nPeWvVs
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4c0UaGIbiDKUOQ9nPeWvVs
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7DHISgo9Uu4sgGrntWv6Hw
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7DHISgo9Uu4sgGrntWv6Hw
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3ywnVanY59SrPxNhhSUrN8
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3ywnVanY59SrPxNhhSUrN8
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4DpSEMsOSibGpgVEmI5G5B
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4DpSEMsOSibGpgVEmI5G5B
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5y25DV4hGYUizcnAH1kFgM
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:5y25DV4hGYUizcnAH1kFgM
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:45QRBDrfLXVvJn2VeGPQCn
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:45QRBDrfLXVvJn2VeGPQCn
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:546OjMyW4EJhqveZmqtgsQ
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:546OjMyW4EJhqveZmqtgsQ
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:16MIqM8waXb51nI94J3iAO
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:16MIqM8waXb51nI94J3iAO
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1pDaIv4kERYDqeCzYDpZ80
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1pDaIv4kERYDqeCzYDpZ80
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7pUBBayxQ3YaKrVSurhjG4
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7pUBBayxQ3YaKrVSurhjG4
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:22jfmM32Om1nFXPmJnxDcs
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:22jfmM32Om1nFXPmJnxDcs
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:75S0mJv5bWWO6kJ2BvPgpK
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:75S0mJv5bWWO6kJ2BvPgpK
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:58zypYCPl2jwCI63sg8J4W
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:58zypYCPl2jwCI63sg8J4W
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3GeFIptUSLYybmyhkPVjjf
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3GeFIptUSLYybmyhkPVjjf
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2QVXnSWUAPNGZ1GuV6rAnP
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:2QVXnSWUAPNGZ1GuV6rAnP
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:69EhXRbe17FYLqqdpB0jnC
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:69EhXRbe17FYLqqdpB0jnC
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:25UJzWEeCK3wGslX8iLrt2
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:25UJzWEeCK3wGslX8iLrt2
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7CMkMpcVK6MofjXM8vSAnd
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7CMkMpcVK6MofjXM8vSAnd
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3D6ZPZrFk2CHZCJ2STxHW7
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3D6ZPZrFk2CHZCJ2STxHW7
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4s7uHuYDYp0bACtrsGcXTD
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4s7uHuYDYp0bACtrsGcXTD
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:5bA0ZDc7qg5R1qxINkIB2D
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:5bA0ZDc7qg5R1qxINkIB2D
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4Hi1Wnq7pq3T8XJKBhmCMP
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4Hi1Wnq7pq3T8XJKBhmCMP
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0Xm0dF2MmJctbAi5iz64XL
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0Xm0dF2MmJctbAi5iz64XL
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4Qx8xQSOhYMtIDh5liCDpF
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4Qx8xQSOhYMtIDh5liCDpF
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3G1QJ5yuNw385SULJFEjzJ
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3G1QJ5yuNw385SULJFEjzJ
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:3SxwydxyvGo3Um32X7vTEY
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:3SxwydxyvGo3Um32X7vTEY
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:4KLup5onhhZjysHCT89upc
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:4KLup5onhhZjysHCT89upc
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1yTk2dEtxvvLTisREsDyVe
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1yTk2dEtxvvLTisREsDyVe
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1zXTJp4mMwu2y69LajfzFK
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1zXTJp4mMwu2y69LajfzFK
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:34sbAfcmrPhJqpszzwMyhv
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:34sbAfcmrPhJqpszzwMyhv
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:74UuxmgXCk9lE6GjDJRLkH
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:74UuxmgXCk9lE6GjDJRLkH
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1dEtXRznHGSyWNwmpmKXWn
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1dEtXRznHGSyWNwmpmKXWn
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:1AjSrQPfK7PlyE6HPAidXh
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:1AjSrQPfK7PlyE6HPAidXh
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:774kFk9YCPyTYR7sSIDqum
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:774kFk9YCPyTYR7sSIDqum
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:67ysFzoO0jw9lX700WCE2j
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:67ysFzoO0jw9lX700WCE2j
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:7Bn3fVcSIpoTUwDIzWom0Q
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:7Bn3fVcSIpoTUwDIzWom0Q
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2wu3hOKDKAO0TgC78RmSvZ
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:2wu3hOKDKAO0TgC78RmSvZ
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:2c3XylA6lP5W2qHiPYuV2W
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:2c3XylA6lP5W2qHiPYuV2W
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:0EDi8nGDIcZ0PmvoS9pOVC
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:0EDi8nGDIcZ0PmvoS9pOVC
Oct 03 21:11:51 volumio volumio[1189]: info: Adding Item to queue: spotify:track:49ZO03I7BV9oLHbWbnlJIg
Oct 03 21:11:51 volumio volumio[1189]: info: Using cached record of: spotify:track:49ZO03I7BV9oLHbWbnlJIg
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioPlay
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::play index 47
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::play index undefined
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:51 volumio volumio[1189]: info: [1727982711349] ControllerSpotify::clearAddPlayTrack
Oct 03 21:11:51 volumio volumio[1189]: info: Sending Spotify command with payload to local API: /player/play
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="pause track at 15463ms"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=trace msg="emitting websocket event: paused"
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","play_origin":"go-librespot"}}
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:51 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:51 volumio volumio[1189]: verbose: CURRENT POSITION 47
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:69EhXRbe17FYLqqdpB0jnC","play_origin":"go-librespot"}}
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:51 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:51 volumio volumio[1189]: verbose: CURRENT POSITION 47
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:51 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:51 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:51 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="resolved context of track" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=trace msg="emitting websocket event: will_play"
Oct 03 21:11:51 volumio volumio[1189]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","play_origin":"go-librespot"}}
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="selected format OGG_VORBIS_320 (79a77b0a5a74bfffb40a48be8e62e6ee14d7c9bf)" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="requested aes key for file 79a77b0a5a74bfffb40a48be8e62e6ee14d7c9bf, gid: 5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=debug msg="fetched first chunk of 33, total size is 17099968 bytes" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio go-librespot[20816]: time="2024-10-03T21:11:51+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:51 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=info msg="loaded track \"Skullfucking Neonatal Necrosis\" (paused: false, position: 0ms, duration: 356440ms, prefetched: false)" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=debug msg="fetched chunk 1/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=trace msg="scheduling prefetch in 326s"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=trace msg="emitting websocket event: metadata"
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","name":"Skullfucking Neonatal Necrosis","artist_names":["Visceral Disgorge"],"album_name":"Ingesting Putridity","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","position":0,"duration":356440,"release_date":"year:2013","track_number":9,"disc_number":1}}
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","name":"Skullfucking Neonatal Necrosis","artist_names":["Visceral Disgorge"],"album_name":"Ingesting Putridity","album_cover_url":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","position":0,"duration":356440,"release_date":"year:2013","track_number":9,"disc_number":1}}
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=debug msg="fetched chunk 3/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=debug msg="fetched chunk 2/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:11:52 volumio go-librespot[20816]: time="2024-10-03T21:11:52+02:00" level=trace msg="emitting websocket event: playing"
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","play_origin":"go-librespot"}}
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: verbose: CURRENT POSITION 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","play_origin":"go-librespot"}}
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: verbose: CURRENT POSITION 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:52 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:52 volumio volumio[1189]: info: [LastFM] Current track has sufficient metadata: title (Skullfucking Neonatal Necrosis) and artist (Visceral Disgorge) passed on explicitly
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:52 volumio volumio[1189]: [LastFM] updated "now playing" failed: {
Oct 03 21:11:52 volumio volumio[1189]: success: false,
Oct 03 21:11:52 volumio volumio[1189]: error: 'Invalid parameters - Your request is missing a required parameter'
Oct 03 21:11:52 volumio volumio[1189]: }
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: verbose: CURRENT POSITION 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:52 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d00001e028f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","seek":0,"duration":356,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:11:52 volumio volumio[1189]: verbose: CURRENT POSITION 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:11:52 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:11:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:11:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:11:53 volumio volumio[1189]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Skullfucking Neonatal Necrosis","url":"https://www.last.fm/music/Visceral+Disgorge/_/Skullfucking+Neonatal+Necrosis","duration":"356000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"13139","playcount":"68556","artist":{"name":"Visceral Disgorge","mbid":"f625ebff-9d16-4209-97ec-f006fea3973b","url":"https://www.last.fm/music/Visceral+Disgorge"},"album":{"artist":"Visceral Disgorge","title":"Ingesting Putridity","url":"https://www.last.fm/music/Visceral+Disgorge/Ingesting+Putridity","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/a3fde79a26944c1cb3b42fa8bcbd0a98.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/a3fde79a26944c1cb3b42fa8bcbd0a98.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/a3fde79a26944c1cb3b42fa8bcbd0a98.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/a3fde79a26944c1cb3b42fa8bcbd0a98.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":{"tag":[{"name":"Brutal Death Metal","url":"https://www.last.fm/tag/Brutal+Death+Metal"},{"name":"death metal","url":"https://www.last.fm/tag/death+metal"},{"name":"Slamming Brutal Death Metal","url":"https://www.last.fm/tag/Slamming+Brutal+Death+Metal"}]}}}
Oct 03 21:11:54 volumio volumio[1189]: info: CoreCommandRouter::volumioGetState
Oct 03 21:11:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:12:02 volumio go-librespot[20816]: time="2024-10-03T21:12:02+02:00" level=debug msg="fetched chunk 4/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:12:12 volumio go-librespot[20816]: time="2024-10-03T21:12:12+02:00" level=debug msg="fetched chunk 5/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:12:23 volumio go-librespot[20816]: time="2024-10-03T21:12:23+02:00" level=debug msg="fetched chunk 6/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:12:33 volumio go-librespot[20816]: time="2024-10-03T21:12:33+02:00" level=debug msg="fetched chunk 7/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:12:38 volumio volumio[1189]: info: CoreCommandRouter::volumioAddQueueItems
Oct 03 21:12:38 volumio volumio[1189]: info: CoreStateMachine::addQueueItems
Oct 03 21:12:38 volumio volumio[1189]: info: CorePlayQueue::addQueueItems
Oct 03 21:12:38 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:12:38 volumio volumio[1189]: info: Adding Item to queue: spotify:playlist:0l4ex9kcd2adb3yLUqgNG9
Oct 03 21:12:38 volumio volumio[1189]: info: Exploding uri spotify:playlist:0l4ex9kcd2adb3yLUqgNG9 in service spop
Oct 03 21:12:38 volumio volumio[1189]: SPOTIFY: EXPLODING URI:spotify:playlist:0l4ex9kcd2adb3yLUqgNG9
Oct 03 21:12:39 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:12:39 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:12:39 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:12:39 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:12:45 volumio go-librespot[20816]: time="2024-10-03T21:12:45+02:00" level=debug msg="fetched chunk 8/32, size: 524288" uri="spotify:track:5bA0ZDc7qg5R1qxINkIB2D"
Oct 03 21:12:52 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::ClearQueue
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::stPlaybackTimer
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::serviceStop
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 47
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::serviceStop
Oct 03 21:12:52 volumio volumio[1189]: info: Spotify Stop
Oct 03 21:12:52 volumio volumio[1189]: SPOTIFY: SPOTIFY STOP
Oct 03 21:12:52 volumio volumio[1189]: SPOTIFY: {"status":"play","position":47,"title":"Skullfucking Neonatal Necrosis","artist":"Visceral Disgorge","album":"Ingesting Putridity","albumart":"https://i.scdn.co/image/ab67616d0000b2738f0bf3696b0546fb5f3e1ae2","uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","trackType":"spotify","codec":"ogg","seek":0,"duration":356,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":29,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Oct 03 21:12:52 volumio volumio[1189]: info: Sending Spotify command to local API: /player/pause
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::clearPlayQueue
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::addQueueItems
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::addQueueItems
Oct 03 21:12:52 volumio volumio[1189]: info: Preload queue cleared
Oct 03 21:12:52 volumio volumio[1189]: info: Adding Item to queue: spotify:playlist:0l4ex9kcd2adb3yLUqgNG9
Oct 03 21:12:52 volumio volumio[1189]: info: Using cached record of: spotify:playlist:0l4ex9kcd2adb3yLUqgNG9
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::saveQueue
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock
Oct 03 21:12:52 volumio volumio[1189]: info: CoreCommandRouter::volumioPlay
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::play index 0
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::stop
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::play index undefined
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:52 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer
Oct 03 21:12:52 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:52 volumio volumio[1189]: info: [1727982772930] ControllerSpotify::clearAddPlayTrack
Oct 03 21:12:52 volumio volumio[1189]: info: Sending Spotify command with payload to local API: /player/play
Oct 03 21:12:52 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:52 volumio go-librespot[20816]: time="2024-10-03T21:12:52+02:00" level=debug msg="pause track at 61068ms"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="emitting websocket event: paused"
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","play_origin":"go-librespot"}}
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: verbose: CURRENT POSITION 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5bA0ZDc7qg5R1qxINkIB2D","play_origin":"go-librespot"}}
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: verbose: CURRENT POSITION 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="resolved context of track" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="emitting websocket event: will_play"
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","play_origin":"go-librespot"}}
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","play_origin":"go-librespot"}}
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="selected format OGG_VORBIS_320 (5bba92c3346832346f5ee0d97d8b87818959d7cb)" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="requested aes key for file 5bba92c3346832346f5ee0d97d8b87818959d7cb, gid: 7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="fetched first chunk of 20, total size is 10073464 bytes" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=info msg="loaded track \"Let The Blood Spill Between My Broken Teeth\" (paused: false, position: 0ms, duration: 234066ms, prefetched: false)" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="scheduling prefetch in 204s"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="emitting websocket event: metadata"
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","name":"Let The Blood Spill Between My Broken Teeth","artist_names":["Benighted"],"album_name":"Asylum Cave","album_cover_url":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","position":0,"duration":234066,"release_date":"year:2012 month:11 day:10","track_number":2,"disc_number":1}}
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","name":"Let The Blood Spill Between My Broken Teeth","artist_names":["Benighted"],"album_name":"Asylum Cave","album_cover_url":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","position":0,"duration":234066,"release_date":"year:2012 month:11 day:10","track_number":2,"disc_number":1}}
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=trace msg="emitting websocket event: playing"
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","play_origin":"go-librespot"}}
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: verbose: CURRENT POSITION 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","play_origin":"go-librespot"}}
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:53 volumio volumio[1189]: verbose: CURRENT POSITION 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:12:53 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:53 volumio go-librespot[20816]: time="2024-10-03T21:12:53+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:7dfyknuaAWlEdprIhXPuml"
Oct 03 21:12:53 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:53 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:53 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:53 volumio volumio[1189]: info: [LastFM] Current track has sufficient metadata: title (Let The Blood Spill Between My Broken Teeth) and artist (Benighted) passed on explicitly
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:53 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:53 volumio volumio[1189]: [LastFM] updated "now playing" failed: {
Oct 03 21:12:53 volumio volumio[1189]: success: false,
Oct 03 21:12:53 volumio volumio[1189]: error: 'Invalid parameters - Your request is missing a required parameter'
Oct 03 21:12:53 volumio volumio[1189]: }
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:54 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:12:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:54 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:54 volumio volumio[1189]: verbose: CURRENT POSITION 0
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:12:54 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:54 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:54 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: PUSH STATE SPOTIFY
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:54 volumio volumio[1189]: info: CoreCommandRouter::servicePushState
Oct 03 21:12:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:54 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Let The Blood Spill Between My Broken Teeth","artist":"Benighted","album":"Asylum Cave","albumart":"https://i.scdn.co/image/ab67616d00001e022c982a761d9b77ba70539080","uri":"spotify:track:7dfyknuaAWlEdprIhXPuml","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Oct 03 21:12:54 volumio volumio[1189]: verbose: CURRENT POSITION 0
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play
Oct 03 21:12:54 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:54 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:54 volumio volumio[1189]: info: CoreStateMachine::pushState
Oct 03 21:12:54 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:54 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:54 volumio volumio[1189]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Oct 03 21:12:56 volumio volumio[1189]: info: CoreCommandRouter::volumioGetState
Oct 03 21:12:56 volumio volumio[1189]: info: CorePlayQueue::getTrack 0
Oct 03 21:12:57 volumio volumio[1189]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 03 21:12:57 volumio volumio[1189]: TypeError: Cannot read property '@' of null
Oct 03 21:12:57 volumio volumio[1189]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14)
Oct 03 21:12:57 volumio volumio[1189]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13
Oct 03 21:12:57 volumio volumio[1189]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:304:18)
Oct 03 21:12:57 volumio volumio[1189]: at Parser.emit (events.js:315:20)
Oct 03 21:12:57 volumio volumio[1189]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:314:16)
Oct 03 21:12:57 volumio volumio[1189]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59)
Oct 03 21:12:57 volumio volumio[1189]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14)
Oct 03 21:12:57 volumio volumio[1189]: at IncomingMessage.emit (events.js:327:22)
Oct 03 21:12:57 volumio volumio[1189]: at endReadableNT (internal/streams/readable.js:1327:12)
Oct 03 21:12:57 volumio volumio[1189]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Oct 03 21:12:57 volumio volumio[1189]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 03 21:12:57 volumio sudo[5841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-03 21:11
Oct 03 21:12:57 volumio sudo[5841]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST"
VOLUMIO_VERSION="3.757"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"