-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Mon 2025-01-20 14:42:50 EST. -- Jan 20 14:41:02 volumio volumio[871]: info: CALLMETHOD: audio_interface fusiondsp disableeffect undefined Jan 20 14:41:02 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , disableeffect Jan 20 14:41:02 volumio volumio[871]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 20 14:41:02 volumio volumio[871]: info: FusionDsp - Effects disabled Jan 20 14:41:02 volumio volumio[871]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 14:41:02 volumio volumio[871]: info: CoreCommandRouter::Close All Modals sent Jan 20 14:41:02 volumio volumio[871]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 20 14:41:09 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:41:09 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:11 volumio go-librespot[19334]: time="2025-01-20T14:41:11-05:00" level=debug msg="fetched chunk 9/34, size: 524288" uri="spotify:track:48ZqiKc9qMhrOTMctjwYOw" Jan 20 14:41:19 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:41:19 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:19 volumio volumio[871]: info: Listing playlists Jan 20 14:41:19 volumio volumio[871]: info: Listing playlists Jan 20 14:41:25 volumio go-librespot[19334]: time="2025-01-20T14:41:25-05:00" level=debug msg="fetched chunk 10/34, size: 524288" uri="spotify:track:48ZqiKc9qMhrOTMctjwYOw" Jan 20 14:41:29 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:41:29 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:39 volumio go-librespot[19334]: time="2025-01-20T14:41:39-05:00" level=debug msg="fetched chunk 11/34, size: 524288" uri="spotify:track:48ZqiKc9qMhrOTMctjwYOw" Jan 20 14:41:39 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:41:39 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:39 volumio volumio[871]: info: Listing playlists Jan 20 14:41:39 volumio volumio[871]: info: Listing playlists Jan 20 14:41:49 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:41:49 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::volumioNext Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::next Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::stop Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::stPlaybackTimer Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::updateTrackBlock Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrackBlock Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::serviceStop Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::serviceStop Jan 20 14:41:51 volumio volumio[871]: info: Spotify Stop Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: SPOTIFY STOP Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: {"status":"play","position":0,"title":"The Package","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d0000b2739fce7baa218063d99799ce52","uri":"spotify:track:48ZqiKc9qMhrOTMctjwYOw","trackType":"spotify","codec":"ogg","seek":53079,"duration":460,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jan 20 14:41:51 volumio volumio[871]: info: Sending Spotify command to local API: /player/pause Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::play index undefined Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::startPlaybackTimer Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:51 volumio volumio[871]: info: [1737402111465] ControllerSpotify::clearAddPlayTrack Jan 20 14:41:51 volumio volumio[871]: info: Sending Spotify command with payload to local API: /player/play Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::updateTrackBlock Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrackBlock Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=debug msg="pause track at 120951ms" Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=trace msg="emitting websocket event: paused" Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:48ZqiKc9qMhrOTMctjwYOw","play_origin":"go-librespot"}} Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:41:51 volumio volumio[871]: 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} Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:51 volumio volumio[871]: 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} Jan 20 14:41:51 volumio volumio[871]: verbose: CURRENT POSITION 1 Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::syncState stateService pause Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus stop Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:48ZqiKc9qMhrOTMctjwYOw","play_origin":"go-librespot"}} Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:41:51 volumio volumio[871]: 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} Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:51 volumio volumio[871]: 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} Jan 20 14:41:51 volumio volumio[871]: verbose: CURRENT POSITION 1 Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::syncState stateService pause Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus stop Jan 20 14:41:51 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:51 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:51 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:51 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=debug msg="resolved context of track" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:51 volumio go-librespot[19334]: time="2025-01-20T14:41:51-05:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=trace msg="emitting websocket event: will_play" Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","play_origin":"go-librespot"}} Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","play_origin":"go-librespot"}} Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="selected format OGG_VORBIS_320 (33b2d42f3dfc939a01201a9220cd9e6589c807a8)" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="requested aes key for file 33b2d42f3dfc939a01201a9220cd9e6589c807a8, gid: 7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="fetched first chunk of 17, total size is 8613864 bytes" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - Effects disabled Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=info msg="loaded track \"Weak And Powerless\" (paused: false, position: 0ms, duration: 195133ms, prefetched: false)" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - Effects disabled Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 20 14:41:52 volumio volumio[871]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) Jan 20 14:41:52 volumio volumio[871]: info: camilladsp spawned new process with pid 20644, instance 1, run: true Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=trace msg="scheduling prefetch in 165s" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=trace msg="emitting websocket event: metadata" Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","name":"Weak And Powerless","artist_names":["A Perfect Circle"],"album_name":"Thirteenth Step","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","position":0,"duration":195133,"release_date":"year:2003 month:1 day:1","track_number":2,"disc_number":1}} Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","name":"Weak And Powerless","artist_names":["A Perfect Circle"],"album_name":"Thirteenth Step","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","position":0,"duration":195133,"release_date":"year:2003 month:1 day:1","track_number":2,"disc_number":1}} Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:41:52 volumio go-librespot[19334]: time="2025-01-20T14:41:52-05:00" level=trace msg="emitting websocket event: playing" Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","play_origin":"go-librespot"}} Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:52 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:41:52 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:52 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:52 volumio volumio[871]: verbose: CURRENT POSITION 1 Jan 20 14:41:52 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:41:52 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus stop Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","play_origin":"go-librespot"}} Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:52 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:41:52 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:52 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:52 volumio volumio[871]: verbose: CURRENT POSITION 1 Jan 20 14:41:52 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:41:52 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus play Jan 20 14:41:52 volumio volumio[871]: info: Received an update from plugin. extracting info from payload Jan 20 14:41:52 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:52 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:52 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 14:41:52 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:52 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:52 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:52 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:52 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:53 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:41:53 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:53 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:53 volumio volumio[871]: verbose: CURRENT POSITION 1 Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus play Jan 20 14:41:53 volumio volumio[871]: info: Received an update from plugin. extracting info from payload Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:53 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:53 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:53 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:53 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:53 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:41:53 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:53 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d00001e029fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","seek":0,"duration":195,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:41:53 volumio volumio[871]: verbose: CURRENT POSITION 1 Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus play Jan 20 14:41:53 volumio volumio[871]: info: Received an update from plugin. extracting info from payload Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:53 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:53 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:53 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:41:53 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:53 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:53 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:41:59 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:41:59 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:41:59 volumio volumio[871]: info: Listing playlists Jan 20 14:41:59 volumio volumio[871]: info: Listing playlists Jan 20 14:42:04 volumio go-librespot[19334]: time="2025-01-20T14:42:04-05:00" level=debug msg="fetched chunk 4/16, size: 524288" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:42:09 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:42:09 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:42:16 volumio go-librespot[19334]: time="2025-01-20T14:42:16-05:00" level=debug msg="fetched chunk 5/16, size: 524288" uri="spotify:track:7gDVjl5fEw2OPAtjbW4LzR" Jan 20 14:42:17 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Jan 20 14:42:17 volumio volumio[871]: info: In handleBrowseUri, curUri=spotify:album:0IOTRhN3vY3JwU1g8qSTMO Jan 20 14:42:17 volumio volumio[871]: info: Preload queue cleared Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:6qfOsQO3JIIkICcBmrObmN Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:1yeXZK8FpejylbdGChJ66U Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:16Vxt9gZQRgvltlmkRQOtL Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:7JWdjrja1Jr6iF5qGowzB1 Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:4f8e3cvQgFKPMBAQyCmNZk Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:7d3fA21IrZRStK82ZNE8yk Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:2NrIc4RmGMUt1jMyQM0Th4 Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:40uQVqf8oGvt4fHnE78v2Y Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:3mk6cGPU0aB3ZZP5OP0bMW Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:2HjB9opUR7euVPHTqqjpwD Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:2r6v6ngrnaTVF24JqrRf8o Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:5RvEtk4ckEfGXkFigc3Oml Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:6DHwXB8mA3YJolzriAMCUC Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:2mieXCqCH44F2fM0O0yLbJ Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:5yth6XTvV4wX7hRP0uCxaA Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:2mP6OeSlMATIpgxmSPpjq5 Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:7IT2DYBQBgFBhkFsstrVwQ Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:0jMig0jiJJBk3lmeR7dwAV Jan 20 14:42:17 volumio volumio[871]: info: Preloading song: spotify:track:62Pbu5FAZcC4j1wtdwDNOm Jan 20 14:42:17 volumio volumio[871]: info: Exploding uri spotify:track:6qfOsQO3JIIkICcBmrObmN in service spop Jan 20 14:42:17 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:6qfOsQO3JIIkICcBmrObmN Jan 20 14:42:17 volumio volumio[871]: info: No valid Plugin REST Endpoint Jan 20 14:42:17 volumio volumio[871]: info: No valid Plugin REST Endpoint Jan 20 14:42:17 volumio volumio[871]: info: Exploding uri spotify:track:1yeXZK8FpejylbdGChJ66U in service spop Jan 20 14:42:17 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:1yeXZK8FpejylbdGChJ66U Jan 20 14:42:17 volumio volumio[871]: info: Exploding uri spotify:track:16Vxt9gZQRgvltlmkRQOtL in service spop Jan 20 14:42:17 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:16Vxt9gZQRgvltlmkRQOtL Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:7JWdjrja1Jr6iF5qGowzB1 in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:7JWdjrja1Jr6iF5qGowzB1 Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","service":"spop","name":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":178,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:4f8e3cvQgFKPMBAQyCmNZk in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:4f8e3cvQgFKPMBAQyCmNZk Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1yeXZK8FpejylbdGChJ66U","service":"spop","name":"Rose","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:7d3fA21IrZRStK82ZNE8yk in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:7d3fA21IrZRStK82ZNE8yk Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:16Vxt9gZQRgvltlmkRQOtL","service":"spop","name":"Judith","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":244,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:2NrIc4RmGMUt1jMyQM0Th4 in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:2NrIc4RmGMUt1jMyQM0Th4 Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7JWdjrja1Jr6iF5qGowzB1","service":"spop","name":"Orestes","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":285,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:40uQVqf8oGvt4fHnE78v2Y in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:40uQVqf8oGvt4fHnE78v2Y Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4f8e3cvQgFKPMBAQyCmNZk","service":"spop","name":"3 Libras","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:3mk6cGPU0aB3ZZP5OP0bMW in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:3mk6cGPU0aB3ZZP5OP0bMW Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7d3fA21IrZRStK82ZNE8yk","service":"spop","name":"The Package","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":460,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:2HjB9opUR7euVPHTqqjpwD in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:2HjB9opUR7euVPHTqqjpwD Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2NrIc4RmGMUt1jMyQM0Th4","service":"spop","name":"Weak And Powerless","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":191,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:2r6v6ngrnaTVF24JqrRf8o in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:2r6v6ngrnaTVF24JqrRf8o Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:40uQVqf8oGvt4fHnE78v2Y","service":"spop","name":"The Noose","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":294,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3mk6cGPU0aB3ZZP5OP0bMW","service":"spop","name":"The Outsider","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":246,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:5RvEtk4ckEfGXkFigc3Oml in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:5RvEtk4ckEfGXkFigc3Oml Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:6DHwXB8mA3YJolzriAMCUC in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:6DHwXB8mA3YJolzriAMCUC Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2HjB9opUR7euVPHTqqjpwD","service":"spop","name":"Blue","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":249,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:2mieXCqCH44F2fM0O0yLbJ in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:2mieXCqCH44F2fM0O0yLbJ Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:5yth6XTvV4wX7hRP0uCxaA in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:5yth6XTvV4wX7hRP0uCxaA Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2r6v6ngrnaTVF24JqrRf8o","service":"spop","name":"Imagine","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":287,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:2mP6OeSlMATIpgxmSPpjq5 in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:2mP6OeSlMATIpgxmSPpjq5 Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5RvEtk4ckEfGXkFigc3Oml","service":"spop","name":"Passive","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6DHwXB8mA3YJolzriAMCUC","service":"spop","name":"People Are People - Live","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:7IT2DYBQBgFBhkFsstrVwQ in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:7IT2DYBQBgFBhkFsstrVwQ Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2mieXCqCH44F2fM0O0yLbJ","service":"spop","name":"Counting Bodies Like Sheep To The Rhythm Of The War Drums","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":359,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:0jMig0jiJJBk3lmeR7dwAV in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:0jMig0jiJJBk3lmeR7dwAV Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5yth6XTvV4wX7hRP0uCxaA","service":"spop","name":"When The Levee Breaks","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":354,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: info: Exploding uri spotify:track:62Pbu5FAZcC4j1wtdwDNOm in service spop Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:track:62Pbu5FAZcC4j1wtdwDNOm Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2mP6OeSlMATIpgxmSPpjq5","service":"spop","name":"By And Down","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":333,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7IT2DYBQBgFBhkFsstrVwQ","service":"spop","name":"3 Libras - Live","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":371,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0jMig0jiJJBk3lmeR7dwAV","service":"spop","name":"Gravity - Live","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":310,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:18 volumio volumio[871]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:62Pbu5FAZcC4j1wtdwDNOm","service":"spop","name":"Fiddle And The Drum - Live","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b27368b46756c0b80c077b7db9fb","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Jan 20 14:42:19 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:42:19 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:42:19 volumio volumio[871]: info: Listing playlists Jan 20 14:42:19 volumio volumio[871]: info: Listing playlists Jan 20 14:42:21 volumio volumio[871]: info: Preload queue cleared Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::ClearQueue Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::stop Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::stPlaybackTimer Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::updateTrackBlock Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::getTrackBlock Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::serviceStop Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::getTrack 1 Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::serviceStop Jan 20 14:42:21 volumio volumio[871]: info: Spotify Stop Jan 20 14:42:21 volumio volumio[871]: SPOTIFY: SPOTIFY STOP Jan 20 14:42:21 volumio volumio[871]: SPOTIFY: {"status":"play","position":1,"title":"Weak And Powerless","artist":"A Perfect Circle","album":"Thirteenth Step","albumart":"https://i.scdn.co/image/ab67616d0000b2739fce7baa218063d99799ce52","uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","trackType":"spotify","codec":"ogg","seek":0,"duration":195,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Jan 20 14:42:21 volumio volumio[871]: info: Sending Spotify command to local API: /player/pause Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::clearPlayQueue Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::saveQueue Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::volumioPushQueue Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::addQueueItems Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::addQueueItems Jan 20 14:42:21 volumio volumio[871]: info: Preload queue cleared Jan 20 14:42:21 volumio volumio[871]: info: Adding Item to queue: spotify:album:0IOTRhN3vY3JwU1g8qSTMO Jan 20 14:42:21 volumio volumio[871]: info: Exploding uri spotify:album:0IOTRhN3vY3JwU1g8qSTMO in service spop Jan 20 14:42:21 volumio volumio[871]: SPOTIFY: EXPLODING URI:spotify:album:0IOTRhN3vY3JwU1g8qSTMO Jan 20 14:42:21 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:21 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:21 volumio go-librespot[19334]: time="2025-01-20T14:42:21-05:00" level=debug msg="pause track at 30175ms" Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::volumioPushQueue Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::saveQueue Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::updateTrackBlock Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::getTrackBlock Jan 20 14:42:21 volumio volumio[871]: info: CoreCommandRouter::volumioPlay Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::play index 0 Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::stop Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 14:42:21 volumio go-librespot[19334]: time="2025-01-20T14:42:21-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::play index undefined Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:21 volumio volumio[871]: info: CoreStateMachine::startPlaybackTimer Jan 20 14:42:21 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:21 volumio volumio[871]: info: [1737402141919] ControllerSpotify::clearAddPlayTrack Jan 20 14:42:21 volumio volumio[871]: info: Sending Spotify command with payload to local API: /player/play Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="emitting websocket event: paused" Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","play_origin":"go-librespot"}} Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:42:22 volumio volumio[871]: 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} Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: 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} Jan 20 14:42:22 volumio volumio[871]: verbose: CURRENT POSITION 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState stateService pause Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus stop Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7gDVjl5fEw2OPAtjbW4LzR","play_origin":"go-librespot"}} Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:42:22 volumio volumio[871]: 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} Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: 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} Jan 20 14:42:22 volumio volumio[871]: verbose: CURRENT POSITION 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState stateService pause Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus stop Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="resolved context of track" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="emitting websocket event: will_play" Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","play_origin":"go-librespot"}} Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","play_origin":"go-librespot"}} Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="selected format OGG_VORBIS_320 (513a35e28c878833ede21ce5244fccf49d26eacf)" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="requested aes key for file 513a35e28c878833ede21ce5244fccf49d26eacf, gid: 6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="fetched first chunk of 15, total size is 7505312 bytes" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=info msg="loaded track \"The Hollow\" (paused: false, position: 0ms, duration: 178360ms, prefetched: false)" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio volumio[871]: info: camilladsp spawned new process with pid 20703, instance 1, run: true Jan 20 14:42:22 volumio volumio[871]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 20 14:42:22 volumio volumio[871]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 20 14:42:22 volumio volumio[871]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 20 14:42:22 volumio volumio[871]: info: FusionDsp - Effects disabled Jan 20 14:42:22 volumio volumio[871]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="scheduling prefetch in 147s" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="emitting websocket event: metadata" Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","name":"The Hollow","artist_names":["A Perfect Circle"],"album_name":"Three Sixty (Deluxe Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","position":0,"duration":178360,"release_date":"year:2013 month:1 day:1","track_number":1,"disc_number":1}} Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","name":"The Hollow","artist_names":["A Perfect Circle"],"album_name":"Three Sixty (Deluxe Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","position":0,"duration":178360,"release_date":"year:2013 month:1 day:1","track_number":1,"disc_number":1}} Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 20 14:42:22 volumio go-librespot[19334]: time="2025-01-20T14:42:22-05:00" level=trace msg="emitting websocket event: playing" Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","play_origin":"go-librespot"}} Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:22 volumio volumio[871]: verbose: CURRENT POSITION 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus stop Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","play_origin":"go-librespot"}} Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:22 volumio volumio[871]: verbose: CURRENT POSITION 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus play Jan 20 14:42:22 volumio volumio[871]: info: Received an update from plugin. extracting info from payload Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:22 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:22 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:22 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:22 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio go-librespot[19334]: time="2025-01-20T14:42:23-05:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:23 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:42:23 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:23 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:23 volumio volumio[871]: verbose: CURRENT POSITION 0 Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus play Jan 20 14:42:23 volumio volumio[871]: info: Received an update from plugin. extracting info from payload Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:23 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:23 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:23 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:23 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: PUSH STATE SPOTIFY Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:23 volumio volumio[871]: info: CoreCommandRouter::servicePushState Jan 20 14:42:23 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:23 volumio volumio[871]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"The Hollow","artist":"A Perfect Circle","album":"Three Sixty (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e0268b46756c0b80c077b7db9fb","uri":"spotify:track:6qfOsQO3JIIkICcBmrObmN","trackType":"spotify","seek":0,"duration":178,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 20 14:42:23 volumio volumio[871]: verbose: CURRENT POSITION 0 Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::syncState stateService play Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::syncState currentStatus play Jan 20 14:42:23 volumio volumio[871]: info: Received an update from plugin. extracting info from payload Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:23 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:23 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:23 volumio volumio[871]: info: CoreStateMachine::pushState Jan 20 14:42:23 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:23 volumio volumio[871]: info: CoreCommandRouter::volumioPushState Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:23 volumio volumio[871]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 20 14:42:29 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:42:29 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:34 volumio go-librespot[19334]: time="2025-01-20T14:42:34-05:00" level=debug msg="fetched chunk 4/14, size: 524288" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:37 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 14:42:37 volumio volumio[871]: info: Preload queue cleared Jan 20 14:42:39 volumio volumio[871]: info: CoreCommandRouter::volumioGetState Jan 20 14:42:39 volumio volumio[871]: info: CorePlayQueue::getTrack 0 Jan 20 14:42:39 volumio volumio[871]: info: Listing playlists Jan 20 14:42:39 volumio volumio[871]: info: Listing playlists Jan 20 14:42:40 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 14:42:40 volumio volumio[871]: error: Error browsing0:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"801"}],"errorDescription":[{"_":"Access denied"}]}]}]}]}]}} Jan 20 14:42:40 volumio volumio[871]: error: Failed to execute browseSource: Jan 20 14:42:41 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 14:42:41 volumio volumio[871]: info: Preload queue cleared Jan 20 14:42:43 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 14:42:43 volumio volumio[871]: info: Preload queue cleared Jan 20 14:42:46 volumio go-librespot[19334]: time="2025-01-20T14:42:46-05:00" level=debug msg="fetched chunk 5/14, size: 524288" uri="spotify:track:6qfOsQO3JIIkICcBmrObmN" Jan 20 14:42:48 volumio volumio[871]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 14:42:49 volumio volumio[871]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 14:42:49 volumio volumio[871]: TypeError: Cannot read property 'length' of undefined Jan 20 14:42:49 volumio volumio[871]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jan 20 14:42:49 volumio volumio[871]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jan 20 14:42:49 volumio volumio[871]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jan 20 14:42:49 volumio volumio[871]: at Parser.emit (events.js:315:20) Jan 20 14:42:49 volumio volumio[871]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jan 20 14:42:49 volumio volumio[871]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jan 20 14:42:49 volumio volumio[871]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jan 20 14:42:49 volumio volumio[871]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jan 20 14:42:49 volumio volumio[871]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jan 20 14:42:49 volumio volumio[871]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jan 20 14:42:49 volumio volumio[871]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jan 20 14:42:49 volumio volumio[871]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jan 20 14:42:49 volumio volumio[871]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jan 20 14:42:49 volumio volumio[871]: at IncomingMessage.emit (events.js:327:22) Jan 20 14:42:49 volumio volumio[871]: at endReadableNT (internal/streams/readable.js:1327:12) Jan 20 14:42:49 volumio volumio[871]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jan 20 14:42:49 volumio volumio[871]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 14:42:50 volumio sudo[20826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-20 14:41 Jan 20 14:42:50 volumio sudo[20826]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"