-- Logs begin at Sun 2024-07-21 11:33:18 CEST, end at Sun 2024-07-21 12:40:34 CEST. --
Jul 21 12:39:08 rivo go-librespot[3808]: time="2024-07-21T12:39:08+02:00" level=debug msg="fetched chunk 10/12, size: 524288"
Jul 21 12:39:18 rivo volumio[3129]: verbose: New Socket.io Connection to 192.168.8.173 from 192.168.8.153 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 10
Jul 21 12:39:21 rivo go-librespot[3808]: time="2024-07-21T12:39:21+02:00" level=debug msg="fetched chunk 11/12, size: 524288"
Jul 21 12:39:25 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:25 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:25 rivo volumio[3129]: info: CorePlayQueue::getTrack 1
Jul 21 12:39:25 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:25 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:25 rivo volumio[3129]: info: CorePlayQueue::getTrack 1
Jul 21 12:39:25 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:25 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:25 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:25 rivo volumio[3129]: SPOTIFY: {"status":"play","position":1,"title":"Overdrive (feat. Norma Jean Martine)","artist":"Ofenbach","album":"Overdrive (feat. Norma Jean Martine)","albumart":"https://i.scdn.co/image/ab67616d0000b273249f764814d57dc5dfc462c7","uri":"spotify:track:3bK1zVFBKIzYjmptmI4NsJ","trackType":"spotify","codec":"ogg","seek":311477,"duration":155,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:25 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:25 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:25 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:25 rivo volumio[3129]: info: [1721558365656] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:25 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:25 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:25 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:25 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:25 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:25 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:25 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:25 rivo go-librespot[3808]: time="2024-07-21T12:39:25+02:00" level=debug msg="pause track at 97882ms"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:26 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:3bK1zVFBKIzYjmptmI4NsJ","play_origin":"go-librespot"}}
Jul 21 12:39:26 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:26 rivo volumio[3129]: 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}
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:26 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:26 rivo volumio[3129]: 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}
Jul 21 12:39:26 rivo volumio[3129]: verbose: CURRENT POSITION 2
Jul 21 12:39:26 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:26 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:26 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:26 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:26 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="loading track spotify:track:59NraMJsLaMCVtwXTSia8i (paused: false, position: 0ms)"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:26 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","play_origin":"go-librespot"}}
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:59NraMJsLaMCVtwXTSia8i"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="requested aes key for file a2478feb52190be548c781d9982742c7df93d624, gid: 59NraMJsLaMCVtwXTSia8i"
Jul 21 12:39:26 rivo volumio[3129]: info: camilladsp spawned new process with pid 8040, instance 1, run: true
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=debug msg="fetched first chunk of 13, total size is 6517732 bytes"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Jul 21 12:39:26 rivo go-librespot[3808]: time="2024-07-21T12:39:26+02:00" level=info msg="loaded track \"Prada\" (uri: spotify:track:59NraMJsLaMCVtwXTSia8i, paused: false, position: 0ms, duration: 132359ms)"
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 21 12:39:26 rivo volumio[3129]: info: Discovery: Getting this device information
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Jul 21 12:39:26 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:26 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 21 12:39:26 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","name":"Prada","artist_names":["cassö","RAYE","D-Block Europe"],"album_name":"Prada","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e4b7dccdfd54375ded9ccc5c","position":0,"duration":132359,"release_date":"year:2023 month:8 day:11","track_number":1,"disc_number":1}}
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=debug msg="fetched chunk 1/12, size: 524288"
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=debug msg="fetched chunk 3/12, size: 524288"
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","play_origin":"go-librespot"}}
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Prada","artist":"cassö, RAYE, D-Block Europe","album":"Prada","albumart":"https://i.scdn.co/image/ab67616d00001e02e4b7dccdfd54375ded9ccc5c","uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:27 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:27 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:27 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Prada","artist":"cassö, RAYE, D-Block Europe","album":"Prada","albumart":"https://i.scdn.co/image/ab67616d00001e02e4b7dccdfd54375ded9ccc5c","uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:27 rivo volumio[3129]: verbose: CURRENT POSITION 2
Jul 21 12:39:27 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:27 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Prada","artist":"cassö, RAYE, D-Block Europe","album":"Prada","albumart":"https://i.scdn.co/image/ab67616d00001e02e4b7dccdfd54375ded9ccc5c","uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:27 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:27 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:27 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Prada","artist":"cassö, RAYE, D-Block Europe","album":"Prada","albumart":"https://i.scdn.co/image/ab67616d00001e02e4b7dccdfd54375ded9ccc5c","uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:27 rivo volumio[3129]: verbose: CURRENT POSITION 2
Jul 21 12:39:27 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:27 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:27 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:27 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:27 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:27 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:27 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:27 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:27 rivo go-librespot[3808]: time="2024-07-21T12:39:27+02:00" level=debug msg="fetched chunk 2/12, size: 524288"
Jul 21 12:39:27 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:27 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:27 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:27 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:27 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:27 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:27 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:27 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:27 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:28 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:28 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:28 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrack 2
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:28 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:28 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:28 rivo volumio[3129]: SPOTIFY: {"status":"play","position":2,"title":"Prada","artist":"cassö","album":"Prada","albumart":"https://i.scdn.co/image/ab67616d0000b273e4b7dccdfd54375ded9ccc5c","uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","trackType":"spotify","codec":"ogg","seek":0,"duration":132,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:28 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:28 rivo volumio[3129]: info: [1721558368342] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:28 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:28 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:28 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:28 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:28 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:28 rivo go-librespot[3808]: time="2024-07-21T12:39:28+02:00" level=debug msg="pause track at 2858ms"
Jul 21 12:39:28 rivo go-librespot[3808]: time="2024-07-21T12:39:28+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:28 rivo go-librespot[3808]: time="2024-07-21T12:39:28+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:28 rivo go-librespot[3808]: time="2024-07-21T12:39:28+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:28 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:59NraMJsLaMCVtwXTSia8i","play_origin":"go-librespot"}}
Jul 21 12:39:28 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:28 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:28 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:28 rivo volumio[3129]: verbose: CURRENT POSITION 3
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:28 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:28 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:28 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:29 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="loading track spotify:track:53cHSvMM7cyEcbeUXExOXN (paused: false, position: 0ms)"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:29 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","play_origin":"go-librespot"}}
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:53cHSvMM7cyEcbeUXExOXN"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="requested aes key for file 228990dee761afeb01345042edd1643c59e510b3, gid: 53cHSvMM7cyEcbeUXExOXN"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="fetched first chunk of 14, total size is 7100208 bytes"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=info msg="loaded track \"Strangers\" (uri: spotify:track:53cHSvMM7cyEcbeUXExOXN, paused: false, position: 0ms, duration: 188200ms)"
Jul 21 12:39:29 rivo volumio[3129]: info: camilladsp spawned new process with pid 8054, instance 1, run: true
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:29 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="fetched chunk 1/13, size: 524288"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:29 rivo go-librespot[3808]: time="2024-07-21T12:39:29+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:29 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","name":"Strangers","artist_names":["NALYRO","Giorgio Gee","Eliine"],"album_name":"Strangers","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","position":0,"duration":188200,"release_date":"year:2024 month:1 day:5","track_number":1,"disc_number":1}}
Jul 21 12:39:30 rivo go-librespot[3808]: time="2024-07-21T12:39:30+02:00" level=debug msg="fetched chunk 2/13, size: 524288"
Jul 21 12:39:30 rivo go-librespot[3808]: time="2024-07-21T12:39:30+02:00" level=debug msg="fetched chunk 3/13, size: 524288"
Jul 21 12:39:30 rivo go-librespot[3808]: time="2024-07-21T12:39:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:30 rivo go-librespot[3808]: time="2024-07-21T12:39:30+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","play_origin":"go-librespot"}}
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Strangers","artist":"NALYRO, Giorgio Gee, Eliine","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","seek":0,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:30 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:30 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:30 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Strangers","artist":"NALYRO, Giorgio Gee, Eliine","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","seek":0,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:30 rivo volumio[3129]: verbose: CURRENT POSITION 3
Jul 21 12:39:30 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:30 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Strangers","artist":"NALYRO, Giorgio Gee, Eliine","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","seek":0,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:30 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:30 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:30 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Strangers","artist":"NALYRO, Giorgio Gee, Eliine","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","seek":0,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:30 rivo volumio[3129]: verbose: CURRENT POSITION 3
Jul 21 12:39:30 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:30 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:30 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:30 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:30 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:30 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:30 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:30 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:30 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:30 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:30 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:30 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:30 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:30 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:30 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:30 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:30 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:31 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:31 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:31 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:31 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:31 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:31 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:31 rivo volumio[3129]: info: CoreCommandRouter::volumioSeek
Jul 21 12:39:31 rivo volumio[3129]: info: CoreStateMachine::seek
Jul 21 12:39:31 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:31 rivo volumio[3129]: info: TRACKBLOCK {"uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","service":"spop","name":"Strangers","artist":"NALYRO","album":"Strangers","type":"song","duration":188,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee5ffd12bdffc3a6baf1123a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2}
Jul 21 12:39:31 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:31 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:31 rivo volumio[3129]: info: Spotify seek to: 58000
Jul 21 12:39:31 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/seek
Jul 21 12:39:31 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:31 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:31 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:31 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:31 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:31 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:31 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:31 rivo go-librespot[3808]: time="2024-07-21T12:39:31+02:00" level=debug msg="seek track to 58000ms"
Jul 21 12:39:31 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:31 rivo go-librespot[3808]: time="2024-07-21T12:39:31+02:00" level=trace msg="seek to 58000ms (diff: 158ms, samples: 2557800, bytes: 2076141)"
Jul 21 12:39:32 rivo go-librespot[3808]: time="2024-07-21T12:39:32+02:00" level=debug msg="fetched chunk 4/13, size: 524288"
Jul 21 12:39:32 rivo go-librespot[3808]: time="2024-07-21T12:39:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:32 rivo go-librespot[3808]: time="2024-07-21T12:39:32+02:00" level=trace msg="emitting websocket event: seek"
Jul 21 12:39:32 rivo volumio[3129]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","position":58000,"duration":188200,"play_origin":"go-librespot"}}
Jul 21 12:39:32 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:32 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Strangers","artist":"NALYRO, Giorgio Gee, Eliine","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","seek":58000,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:32 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:32 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:32 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Strangers","artist":"NALYRO, Giorgio Gee, Eliine","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d00001e02ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","seek":58000,"duration":188,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:32 rivo volumio[3129]: verbose: CURRENT POSITION 3
Jul 21 12:39:32 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:32 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:32 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:32 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:32 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:32 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:32 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:32 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:32 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:32 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:32 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:32 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:32 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:32 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:32 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:32 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:32 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:32 rivo go-librespot[3808]: time="2024-07-21T12:39:32+02:00" level=debug msg="fetched chunk 5/13, size: 524288"
Jul 21 12:39:32 rivo go-librespot[3808]: time="2024-07-21T12:39:32+02:00" level=debug msg="fetched chunk 6/13, size: 524288"
Jul 21 12:39:32 rivo go-librespot[3808]: time="2024-07-21T12:39:32+02:00" level=debug msg="fetched chunk 7/13, size: 524288"
Jul 21 12:39:33 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:33 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:33 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:33 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:33 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:33 rivo volumio[3129]: info: CorePlayQueue::getTrack 3
Jul 21 12:39:33 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:33 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:33 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:33 rivo volumio[3129]: SPOTIFY: {"status":"play","position":3,"title":"Strangers","artist":"NALYRO","album":"Strangers","albumart":"https://i.scdn.co/image/ab67616d0000b273ee5ffd12bdffc3a6baf1123a","uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","trackType":"spotify","codec":"ogg","seek":58000,"duration":188,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:33 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:33 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:33 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:33 rivo volumio[3129]: info: [1721558373547] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:33 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:33 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:33 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:33 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:33 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:33 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:33 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:33 rivo go-librespot[3808]: time="2024-07-21T12:39:33+02:00" level=debug msg="pause track at 59715ms"
Jul 21 12:39:33 rivo go-librespot[3808]: time="2024-07-21T12:39:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:34 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:53cHSvMM7cyEcbeUXExOXN","play_origin":"go-librespot"}}
Jul 21 12:39:34 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:34 rivo volumio[3129]: 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}
Jul 21 12:39:34 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:34 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:34 rivo volumio[3129]: 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}
Jul 21 12:39:34 rivo volumio[3129]: verbose: CURRENT POSITION 4
Jul 21 12:39:34 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:34 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:34 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:34 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:34 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:34 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:34 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:34 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:34 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:34 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=debug msg="loading track spotify:track:0GTuyzPTs2G0wqFD1trSOw (paused: false, position: 0ms)"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:34 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","play_origin":"go-librespot"}}
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0GTuyzPTs2G0wqFD1trSOw"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=debug msg="requested aes key for file 3d2c3579b7b922c76065e6bb887c1c43f12ef7d7, gid: 0GTuyzPTs2G0wqFD1trSOw"
Jul 21 12:39:34 rivo volumio[3129]: info: camilladsp spawned new process with pid 8070, instance 1, run: true
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=debug msg="fetched first chunk of 14, total size is 6911720 bytes"
Jul 21 12:39:34 rivo go-librespot[3808]: time="2024-07-21T12:39:34+02:00" level=trace msg="seek to 0ms (diff: -36ms, samples: 0, bytes: 2213)"
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=info msg="loaded track \"Phone\" (uri: spotify:track:0GTuyzPTs2G0wqFD1trSOw, paused: false, position: 0ms, duration: 155076ms)"
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:35 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=debug msg="fetched chunk 1/13, size: 524288"
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=debug msg="fetched chunk 3/13, size: 524288"
Jul 21 12:39:35 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","name":"Phone","artist_names":["MEDUZA","Sam Tompkins","Em Beihold"],"album_name":"Phone","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","position":0,"duration":155076,"release_date":"year:2023 month:7 day:7","track_number":1,"disc_number":1}}
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=debug msg="fetched chunk 2/13, size: 524288"
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:35 rivo go-librespot[3808]: time="2024-07-21T12:39:35+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:35 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","play_origin":"go-librespot"}}
Jul 21 12:39:35 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:35 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Phone","artist":"MEDUZA, Sam Tompkins, Em Beihold","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","seek":0,"duration":155,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:35 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:35 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:35 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Phone","artist":"MEDUZA, Sam Tompkins, Em Beihold","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","seek":0,"duration":155,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:35 rivo volumio[3129]: verbose: CURRENT POSITION 4
Jul 21 12:39:35 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:35 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:36 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:36 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Phone","artist":"MEDUZA, Sam Tompkins, Em Beihold","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","seek":0,"duration":155,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:36 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:36 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Phone","artist":"MEDUZA, Sam Tompkins, Em Beihold","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","seek":0,"duration":155,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:36 rivo volumio[3129]: verbose: CURRENT POSITION 4
Jul 21 12:39:36 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:36 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:36 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:36 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:36 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:36 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:36 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:36 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:36 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:36 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:36 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:36 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:36 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:36 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:36 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:36 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:36 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:38 rivo volumio[3129]: info: CoreCommandRouter::volumioSeek
Jul 21 12:39:38 rivo volumio[3129]: info: CoreStateMachine::seek
Jul 21 12:39:38 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:38 rivo volumio[3129]: info: TRACKBLOCK {"uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","service":"spop","name":"Phone","artist":"MEDUZA","album":"Phone","type":"song","duration":155,"albumart":"https://i.scdn.co/image/ab67616d0000b2736fd87f346673c7570258d751","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2}
Jul 21 12:39:38 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:38 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:38 rivo volumio[3129]: info: Spotify seek to: 65000
Jul 21 12:39:38 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/seek
Jul 21 12:39:38 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:38 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:38 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:38 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:38 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:38 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:39 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=debug msg="seek track to 65000ms"
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=debug msg="fetched chunk 7/13, size: 524288"
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=debug msg="fetched chunk 5/13, size: 524288"
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=trace msg="seek to 65000ms (diff: 133ms, samples: 2866500, bytes: 2914986)"
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=debug msg="fetched chunk 8/13, size: 524288"
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=trace msg="emitting websocket event: seek"
Jul 21 12:39:39 rivo volumio[3129]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","position":65000,"duration":155076,"play_origin":"go-librespot"}}
Jul 21 12:39:39 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:39 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Phone","artist":"MEDUZA, Sam Tompkins, Em Beihold","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","seek":65000,"duration":155,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:39 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:39 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:39 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Phone","artist":"MEDUZA, Sam Tompkins, Em Beihold","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d00001e026fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","seek":65000,"duration":155,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:39 rivo volumio[3129]: verbose: CURRENT POSITION 4
Jul 21 12:39:39 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:39 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:39 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:39 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:39 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:39 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:39 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:39 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:39 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:39 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:39 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:39 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:39 rivo go-librespot[3808]: time="2024-07-21T12:39:39+02:00" level=debug msg="fetched chunk 6/13, size: 524288"
Jul 21 12:39:40 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:40 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:40 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:40 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:40 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:40 rivo volumio[3129]: info: CorePlayQueue::getTrack 4
Jul 21 12:39:40 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:40 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:40 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:40 rivo volumio[3129]: SPOTIFY: {"status":"play","position":4,"title":"Phone","artist":"MEDUZA","album":"Phone","albumart":"https://i.scdn.co/image/ab67616d0000b2736fd87f346673c7570258d751","uri":"spotify:track:0GTuyzPTs2G0wqFD1trSOw","trackType":"spotify","codec":"ogg","seek":65000,"duration":155,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:40 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:40 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:40 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:40 rivo volumio[3129]: info: [1721558380208] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:40 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:40 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:40 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:40 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:40 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:40 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:40 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:40 rivo go-librespot[3808]: time="2024-07-21T12:39:40+02:00" level=debug msg="pause track at 66158ms"
Jul 21 12:39:40 rivo go-librespot[3808]: time="2024-07-21T12:39:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:40 rivo go-librespot[3808]: time="2024-07-21T12:39:40+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:40 rivo go-librespot[3808]: time="2024-07-21T12:39:40+02:00" level=debug msg="loading track spotify:track:0h3Xy4V4apMraB5NuM8U7Z (paused: false, position: 1ms)"
Jul 21 12:39:40 rivo go-librespot[3808]: time="2024-07-21T12:39:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:40 rivo go-librespot[3808]: time="2024-07-21T12:39:40+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:40 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","play_origin":"go-librespot"}}
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0h3Xy4V4apMraB5NuM8U7Z"
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=debug msg="requested aes key for file 316785cb685f8ff1b542152a87620426f2fed531, gid: 0h3Xy4V4apMraB5NuM8U7Z"
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=debug msg="fetched first chunk of 16, total size is 8157712 bytes"
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)"
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=info msg="loaded track \"Stumblin' In\" (uri: spotify:track:0h3Xy4V4apMraB5NuM8U7Z, paused: false, position: 1ms, duration: 213363ms)"
Jul 21 12:39:41 rivo volumio[3129]: info: camilladsp spawned new process with pid 8129, instance 1, run: true
Jul 21 12:39:41 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:41 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:41 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:41 rivo volumio[3129]: error: FusionDsp - WebSocket error: [object Object]
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=debug msg="fetched chunk 1/15, size: 524288"
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:41 rivo go-librespot[3808]: time="2024-07-21T12:39:41+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:41 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","name":"Stumblin' In","artist_names":["CYRIL"],"album_name":"Stumblin' In","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","position":1,"duration":213363,"release_date":"year:2023 month:11 day:10","track_number":1,"disc_number":1}}
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::volumioSeek
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::seek
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: info: TRACKBLOCK {"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","service":"spop","name":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","type":"song","duration":213,"albumart":"https://i.scdn.co/image/ab67616d0000b2739a903819d8a5d3c80c47734c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: info: Spotify seek to: 64000
Jul 21 12:39:42 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/seek
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="fetched chunk 2/15, size: 524288"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="fetched chunk 3/15, size: 524288"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="seek track to 64000ms"
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","play_origin":"go-librespot"}}
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:42 rivo volumio[3129]: verbose: CURRENT POSITION 5
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="fetched chunk 4/15, size: 524288"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=trace msg="seek to 64000ms (diff: 77ms, samples: 2822400, bytes: 2396135)"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=trace msg="emitting websocket event: seek"
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","position":64000,"duration":213363,"play_origin":"go-librespot"}}
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:42 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":64000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":64000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:42 rivo volumio[3129]: verbose: CURRENT POSITION 5
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:42 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:42 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:42 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:42 rivo go-librespot[3808]: time="2024-07-21T12:39:42+02:00" level=debug msg="fetched chunk 5/15, size: 524288"
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:42 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:43 rivo go-librespot[3808]: time="2024-07-21T12:39:43+02:00" level=debug msg="fetched chunk 6/15, size: 524288"
Jul 21 12:39:43 rivo go-librespot[3808]: time="2024-07-21T12:39:43+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:43 rivo go-librespot[3808]: time="2024-07-21T12:39:43+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","play_origin":"go-librespot"}}
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":64000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:43 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:43 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:43 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":64000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:43 rivo volumio[3129]: verbose: CURRENT POSITION 5
Jul 21 12:39:43 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:43 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:43 rivo go-librespot[3808]: time="2024-07-21T12:39:43+02:00" level=debug msg="fetched chunk 7/15, size: 524288"
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":64000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:43 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:43 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:43 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d00001e029a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","seek":64000,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:43 rivo volumio[3129]: verbose: CURRENT POSITION 5
Jul 21 12:39:43 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:43 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:43 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:43 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:43 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:43 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:43 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:43 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:43 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:43 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:43 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:43 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:44 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:44 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:44 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:44 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:44 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:44 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:46 rivo go-librespot[3808]: time="2024-07-21T12:39:46+02:00" level=debug msg="fetched chunk 8/15, size: 524288"
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrack 5
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:47 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: {"status":"play","position":5,"title":"Stumblin' In","artist":"CYRIL","album":"Stumblin' In","albumart":"https://i.scdn.co/image/ab67616d0000b2739a903819d8a5d3c80c47734c","uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","trackType":"spotify","codec":"ogg","seek":64000,"duration":213,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:47 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:47 rivo volumio[3129]: info: [1721558387264] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:47 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:47 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:47 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:47 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="pause track at 69162ms"
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0h3Xy4V4apMraB5NuM8U7Z","play_origin":"go-librespot"}}
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:47 rivo volumio[3129]: 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}
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:47 rivo volumio[3129]: 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}
Jul 21 12:39:47 rivo volumio[3129]: verbose: CURRENT POSITION 6
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:47 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:47 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:47 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:47 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:47 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:47 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="loading track spotify:track:5OFVzqSeFxGpvDGyHvVeLj (paused: false, position: 0ms)"
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:47 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","play_origin":"go-librespot"}}
Jul 21 12:39:47 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5OFVzqSeFxGpvDGyHvVeLj"
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:47+02:00" level=debug msg="requested aes key for file bc68015731c55a9fac90d50d37f75c424fc63a17, gid: 5OFVzqSeFxGpvDGyHvVeLj"
Jul 21 12:39:48 rivo volumio[3129]: info: camilladsp spawned new process with pid 8143, instance 1, run: true
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:48+02:00" level=debug msg="fetched first chunk of 13, total size is 6464879 bytes"
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:48+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:48+02:00" level=info msg="loaded track \"It's Not Right But It's Okay\" (uri: spotify:track:5OFVzqSeFxGpvDGyHvVeLj, paused: false, position: 0ms, duration: 152304ms)"
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:48 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:48+02:00" level=debug msg="fetched chunk 2/12, size: 524288"
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:48+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:48 rivo go-librespot[3808]: time="2024-07-21T12:39:48+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:48 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","name":"It's Not Right But It's Okay","artist_names":["Mr. Belt \u0026 Wezol"],"album_name":"It's Not Right But It's Okay","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0203f9f7783244b38aec79cb6d","position":0,"duration":152304,"release_date":"year:2024 month:2 day:23","track_number":1,"disc_number":1}}
Jul 21 12:39:49 rivo go-librespot[3808]: time="2024-07-21T12:39:49+02:00" level=debug msg="fetched chunk 1/12, size: 524288"
Jul 21 12:39:49 rivo go-librespot[3808]: time="2024-07-21T12:39:49+02:00" level=debug msg="fetched chunk 3/12, size: 524288"
Jul 21 12:39:49 rivo go-librespot[3808]: time="2024-07-21T12:39:49+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:49 rivo go-librespot[3808]: time="2024-07-21T12:39:49+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","play_origin":"go-librespot"}}
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"It's Not Right But It's Okay","artist":"Mr. Belt & Wezol","album":"It's Not Right But It's Okay","albumart":"https://i.scdn.co/image/ab67616d00001e0203f9f7783244b38aec79cb6d","uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:49 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:49 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"It's Not Right But It's Okay","artist":"Mr. Belt & Wezol","album":"It's Not Right But It's Okay","albumart":"https://i.scdn.co/image/ab67616d00001e0203f9f7783244b38aec79cb6d","uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:49 rivo volumio[3129]: verbose: CURRENT POSITION 6
Jul 21 12:39:49 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:49 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"It's Not Right But It's Okay","artist":"Mr. Belt & Wezol","album":"It's Not Right But It's Okay","albumart":"https://i.scdn.co/image/ab67616d00001e0203f9f7783244b38aec79cb6d","uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:49 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:49 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"It's Not Right But It's Okay","artist":"Mr. Belt & Wezol","album":"It's Not Right But It's Okay","albumart":"https://i.scdn.co/image/ab67616d00001e0203f9f7783244b38aec79cb6d","uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:49 rivo volumio[3129]: verbose: CURRENT POSITION 6
Jul 21 12:39:49 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:49 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:49 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:49 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:49 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:49 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:49 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:49 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:49 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:49 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:49 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:49 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:49 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:49 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:49 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:49 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:49 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:49 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrack 6
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:50 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: {"status":"play","position":6,"title":"It's Not Right But It's Okay","artist":"Mr. Belt & Wezol","album":"It's Not Right But It's Okay","albumart":"https://i.scdn.co/image/ab67616d0000b27303f9f7783244b38aec79cb6d","uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","trackType":"spotify","codec":"ogg","seek":0,"duration":152,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:50 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:50 rivo volumio[3129]: info: [1721558390267] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:50 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:50 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:50 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:50 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="pause track at 2872ms"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5OFVzqSeFxGpvDGyHvVeLj","play_origin":"go-librespot"}}
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:50 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:50 rivo volumio[3129]: verbose: CURRENT POSITION 7
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:50 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:50 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:50 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:50 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:50 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:50 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="loading track spotify:track:70aSLeUZdk85z5zq0TInw5 (paused: false, position: 0ms)"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:50 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","play_origin":"go-librespot"}}
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:70aSLeUZdk85z5zq0TInw5"
Jul 21 12:39:50 rivo go-librespot[3808]: time="2024-07-21T12:39:50+02:00" level=debug msg="requested aes key for file 536dbae84ca86e3294707e33e198ddcca6156466, gid: 70aSLeUZdk85z5zq0TInw5"
Jul 21 12:39:51 rivo volumio[3129]: info: camilladsp spawned new process with pid 8157, instance 1, run: true
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=debug msg="fetched first chunk of 13, total size is 6669708 bytes"
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=trace msg="seek to 0ms (diff: -15ms, samples: 0, bytes: 2542)"
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=info msg="loaded track \"Missing\" (uri: spotify:track:70aSLeUZdk85z5zq0TInw5, paused: false, position: 0ms, duration: 175680ms)"
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:51 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=debug msg="fetched chunk 1/12, size: 524288"
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:51 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","name":"Missing","artist_names":["Giorgio Gee","SRNDE"],"album_name":"Missing","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f16d18a3dc6eec64f3160ad7","position":0,"duration":175680,"release_date":"year:2024 month:5 day:24","track_number":1,"disc_number":1}}
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=debug msg="fetched chunk 3/12, size: 524288"
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:51 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","play_origin":"go-librespot"}}
Jul 21 12:39:51 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:51 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Missing","artist":"Giorgio Gee, SRNDE","album":"Missing","albumart":"https://i.scdn.co/image/ab67616d00001e02f16d18a3dc6eec64f3160ad7","uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","trackType":"spotify","seek":0,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:51 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:51 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:51 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Missing","artist":"Giorgio Gee, SRNDE","album":"Missing","albumart":"https://i.scdn.co/image/ab67616d00001e02f16d18a3dc6eec64f3160ad7","uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","trackType":"spotify","seek":0,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:51 rivo volumio[3129]: verbose: CURRENT POSITION 7
Jul 21 12:39:51 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:51 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:51 rivo go-librespot[3808]: time="2024-07-21T12:39:51+02:00" level=debug msg="fetched chunk 2/12, size: 524288"
Jul 21 12:39:52 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:52 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Missing","artist":"Giorgio Gee, SRNDE","album":"Missing","albumart":"https://i.scdn.co/image/ab67616d00001e02f16d18a3dc6eec64f3160ad7","uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","trackType":"spotify","seek":0,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:52 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:52 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Missing","artist":"Giorgio Gee, SRNDE","album":"Missing","albumart":"https://i.scdn.co/image/ab67616d00001e02f16d18a3dc6eec64f3160ad7","uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","trackType":"spotify","seek":0,"duration":175,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:52 rivo volumio[3129]: verbose: CURRENT POSITION 7
Jul 21 12:39:52 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:52 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:52 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:52 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:52 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:52 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:52 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:52 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:52 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:52 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:52 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:52 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:52 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:52 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:52 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:52 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:52 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:52 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrack 7
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:53 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:53 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:53 rivo volumio[3129]: SPOTIFY: {"status":"play","position":7,"title":"Missing","artist":"Giorgio Gee","album":"Missing","albumart":"https://i.scdn.co/image/ab67616d0000b273f16d18a3dc6eec64f3160ad7","uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","trackType":"spotify","codec":"ogg","seek":0,"duration":175,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:53 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:53 rivo volumio[3129]: info: [1721558393336] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:53 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:53 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:53 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:53 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:53 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:53 rivo go-librespot[3808]: time="2024-07-21T12:39:53+02:00" level=debug msg="pause track at 3156ms"
Jul 21 12:39:53 rivo go-librespot[3808]: time="2024-07-21T12:39:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:53 rivo volumio[3129]: error: Failed request for metavolumio API
Jul 21 12:39:53 rivo go-librespot[3808]: time="2024-07-21T12:39:53+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:53 rivo go-librespot[3808]: time="2024-07-21T12:39:53+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:53 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:70aSLeUZdk85z5zq0TInw5","play_origin":"go-librespot"}}
Jul 21 12:39:53 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:53 rivo volumio[3129]: 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}
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:53 rivo volumio[3129]: 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}
Jul 21 12:39:53 rivo volumio[3129]: verbose: CURRENT POSITION 8
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:53 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:53 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:53 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:53 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:53 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:53 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:53 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:53 rivo go-librespot[3808]: time="2024-07-21T12:39:53+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:53 rivo go-librespot[3808]: time="2024-07-21T12:39:53+02:00" level=debug msg="loading track spotify:track:6BePGk3eCan4FqaW2X8Qy3 (paused: false, position: 0ms)"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:54 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","play_origin":"go-librespot"}}
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6BePGk3eCan4FqaW2X8Qy3"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=debug msg="requested aes key for file e3b0462d22ddd3ef2ef08bcc9a92767197ed565c, gid: 6BePGk3eCan4FqaW2X8Qy3"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=debug msg="fetched first chunk of 15, total size is 7624372 bytes"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Jul 21 12:39:54 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=info msg="loaded track \"10:35\" (uri: spotify:track:6BePGk3eCan4FqaW2X8Qy3, paused: false, position: 0ms, duration: 172252ms)"
Jul 21 12:39:54 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:54 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:54 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:54 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:54 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:54 rivo volumio[3129]: error: FusionDsp - WebSocket error: [object Object]
Jul 21 12:39:54 rivo volumio[3129]: info: camilladsp spawned new process with pid 8172, instance 1, run: true
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=debug msg="fetched chunk 3/14, size: 524288"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:54 rivo go-librespot[3808]: time="2024-07-21T12:39:54+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:54 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","name":"10:35","artist_names":["Tiësto","Tate McRae"],"album_name":"10:35","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02999565cd8bea3f8f0985bb31","position":0,"duration":172252,"release_date":"year:2022 month:11 day:3","track_number":1,"disc_number":1}}
Jul 21 12:39:55 rivo go-librespot[3808]: time="2024-07-21T12:39:55+02:00" level=debug msg="fetched chunk 1/14, size: 524288"
Jul 21 12:39:55 rivo go-librespot[3808]: time="2024-07-21T12:39:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:55 rivo go-librespot[3808]: time="2024-07-21T12:39:55+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:55 rivo go-librespot[3808]: time="2024-07-21T12:39:55+02:00" level=debug msg="fetched chunk 2/14, size: 524288"
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","play_origin":"go-librespot"}}
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"10:35","artist":"Tiësto, Tate McRae","album":"10:35","albumart":"https://i.scdn.co/image/ab67616d00001e02999565cd8bea3f8f0985bb31","uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","trackType":"spotify","seek":0,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:55 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:55 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"10:35","artist":"Tiësto, Tate McRae","album":"10:35","albumart":"https://i.scdn.co/image/ab67616d00001e02999565cd8bea3f8f0985bb31","uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","trackType":"spotify","seek":0,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:55 rivo volumio[3129]: verbose: CURRENT POSITION 8
Jul 21 12:39:55 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:55 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"10:35","artist":"Tiësto, Tate McRae","album":"10:35","albumart":"https://i.scdn.co/image/ab67616d00001e02999565cd8bea3f8f0985bb31","uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","trackType":"spotify","seek":0,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:55 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:55 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"10:35","artist":"Tiësto, Tate McRae","album":"10:35","albumart":"https://i.scdn.co/image/ab67616d00001e02999565cd8bea3f8f0985bb31","uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","trackType":"spotify","seek":0,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:55 rivo volumio[3129]: verbose: CURRENT POSITION 8
Jul 21 12:39:55 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:55 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:55 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:39:55 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:55 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:55 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:55 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:55 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:55 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:55 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:55 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:55 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:55 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:55 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:55 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:55 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:55 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:55 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::volumioSeek
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::seek
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:56 rivo volumio[3129]: info: TRACKBLOCK {"uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","service":"spop","name":"10:35","artist":"Tiësto","album":"10:35","type":"song","duration":172,"albumart":"https://i.scdn.co/image/ab67616d0000b273999565cd8bea3f8f0985bb31","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify","channels":2}
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:56 rivo volumio[3129]: info: Spotify seek to: 60000
Jul 21 12:39:56 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/seek
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:56 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:56 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:56 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:56 rivo go-librespot[3808]: time="2024-07-21T12:39:56+02:00" level=debug msg="seek track to 60000ms"
Jul 21 12:39:56 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 8
Jul 21 12:39:56 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:39:56 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:39:56 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:39:56 rivo volumio[3129]: SPOTIFY: {"status":"play","position":8,"title":"10:35","artist":"Tiësto","album":"10:35","albumart":"https://i.scdn.co/image/ab67616d0000b273999565cd8bea3f8f0985bb31","uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","trackType":"spotify","codec":"ogg","seek":60000,"duration":172,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:39:56 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:56 rivo volumio[3129]: info: [1721558396622] ControllerSpotify::clearAddPlayTrack
Jul 21 12:39:56 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:39:56 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:39:56 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:39:56 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:56 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:56 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:56 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:56 rivo go-librespot[3808]: time="2024-07-21T12:39:56+02:00" level=debug msg="fetched chunk 4/14, size: 524288"
Jul 21 12:39:56 rivo go-librespot[3808]: time="2024-07-21T12:39:56+02:00" level=trace msg="seek to 60000ms (diff: 231ms, samples: 2646000, bytes: 2470320)"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=trace msg="emitting websocket event: seek"
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:6BePGk3eCan4FqaW2X8Qy3","position":60000,"duration":172252,"play_origin":"go-librespot"}}
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: {"status":"stop","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":60000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:57 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:57 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:57 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:57 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:57 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:57 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:57 rivo volumio[3129]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":60000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:57 rivo volumio[3129]: verbose: CURRENT POSITION 9
Jul 21 12:39:57 rivo volumio[3129]: info: CoreStateMachine::syncState stateService stop
Jul 21 12:39:57 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:57 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:57 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:57 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:57 rivo volumio[3129]: info: No code
Jul 21 12:39:57 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:57 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:57 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:57 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=debug msg="fetched chunk 7/14, size: 524288"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=debug msg="fetched chunk 5/14, size: 524288"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=debug msg="loading track spotify:track:4FtVOZM48CHrItbrqfn9Sd (paused: false, position: 102ms)"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=debug msg="fetched chunk 6/14, size: 524288"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:57 rivo go-librespot[3808]: time="2024-07-21T12:39:57+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:39:57 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","play_origin":"go-librespot"}}
Jul 21 12:39:58 rivo go-librespot[3808]: time="2024-07-21T12:39:58+02:00" level=debug msg="fetched chunk 8/14, size: 524288"
Jul 21 12:39:58 rivo go-librespot[3808]: time="2024-07-21T12:39:58+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4FtVOZM48CHrItbrqfn9Sd"
Jul 21 12:39:58 rivo go-librespot[3808]: time="2024-07-21T12:39:58+02:00" level=debug msg="requested aes key for file c597eedb84ad4c79f41b61a92d6fe6678a155ae6, gid: 4FtVOZM48CHrItbrqfn9Sd"
Jul 21 12:39:58 rivo volumio[3129]: info: camilladsp spawned new process with pid 8186, instance 1, run: true
Jul 21 12:39:58 rivo go-librespot[3808]: time="2024-07-21T12:39:58+02:00" level=debug msg="fetched first chunk of 14, total size is 7108492 bytes"
Jul 21 12:39:58 rivo go-librespot[3808]: time="2024-07-21T12:39:58+02:00" level=trace msg="seek to 102ms (diff: 102ms, samples: 4498, bytes: 0)"
Jul 21 12:39:58 rivo go-librespot[3808]: time="2024-07-21T12:39:58+02:00" level=info msg="loaded track \"With You\" (uri: spotify:track:4FtVOZM48CHrItbrqfn9Sd, paused: false, position: 102ms, duration: 168398ms)"
Jul 21 12:39:58 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:39:58 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:39:58 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:58 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="fetched chunk 1/13, size: 524288"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","name":"With You","artist_names":["Lynnic","ItsArius","Dinia"],"album_name":"With You","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","position":102,"duration":168398,"release_date":"year:2023 month:9 day:22","track_number":1,"disc_number":1}}
Jul 21 12:39:59 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:59 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:59 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="pause track at 1827ms"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="fetched chunk 3/13, size: 524288"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="fetched chunk 2/13, size: 524288"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","play_origin":"go-librespot"}}
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":102,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:59 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:59 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":102,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:59 rivo volumio[3129]: verbose: CURRENT POSITION 9
Jul 21 12:39:59 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:39:59 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:39:59 rivo go-librespot[3808]: time="2024-07-21T12:39:59+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","play_origin":"go-librespot"}}
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":102,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:39:59 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:59 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":102,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:39:59 rivo volumio[3129]: verbose: CURRENT POSITION 9
Jul 21 12:39:59 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:39:59 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:39:59 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:39:59 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:39:59 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:39:59 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:39:59 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:39:59 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:39:59 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:00 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:00 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":102,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":102,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:00 rivo volumio[3129]: verbose: CURRENT POSITION 9
Jul 21 12:40:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:40:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:40:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:00 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:00 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:00 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:00 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:00 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:00 rivo volumio[3129]: info: camilladsp spawned new process with pid 8197, instance 1, run: true
Jul 21 12:40:05 rivo volumio[3129]: info: CoreCommandRouter::volumioSeek
Jul 21 12:40:05 rivo volumio[3129]: info: CoreStateMachine::seek
Jul 21 12:40:05 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:05 rivo volumio[3129]: info: TRACKBLOCK {"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","service":"spop","name":"With You","artist":"Lynnic","album":"With You","type":"song","duration":168,"albumart":"https://i.scdn.co/image/ab67616d0000b2736c303579cdd6c93204f090ef","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}
Jul 21 12:40:05 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:40:05 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:05 rivo volumio[3129]: info: Spotify seek to: 50000
Jul 21 12:40:05 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/seek
Jul 21 12:40:05 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:05 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:05 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:05 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:05 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:05 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:05 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:05 rivo go-librespot[3808]: time="2024-07-21T12:40:05+02:00" level=debug msg="seek track to 50000ms"
Jul 21 12:40:05 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=debug msg="fetched chunk 4/13, size: 524288"
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=trace msg="seek to 50000ms (diff: 66ms, samples: 2205000, bytes: 2099067)"
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=debug msg="fetched chunk 5/13, size: 524288"
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=trace msg="emitting websocket event: seek"
Jul 21 12:40:06 rivo volumio[3129]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","position":50000,"duration":168398,"play_origin":"go-librespot"}}
Jul 21 12:40:06 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:06 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":50000,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:06 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:06 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:06 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"With You","artist":"Lynnic, ItsArius, Dinia","album":"With You","albumart":"https://i.scdn.co/image/ab67616d00001e026c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","seek":50000,"duration":168,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:06 rivo volumio[3129]: verbose: CURRENT POSITION 9
Jul 21 12:40:06 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:40:06 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:40:06 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:06 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:06 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:06 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:06 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:06 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:06 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:06 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=debug msg="fetched chunk 6/13, size: 524288"
Jul 21 12:40:06 rivo go-librespot[3808]: time="2024-07-21T12:40:06+02:00" level=debug msg="fetched chunk 7/13, size: 524288"
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrack 9
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:40:16 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: {"status":"play","position":9,"title":"With You","artist":"Lynnic","album":"With You","albumart":"https://i.scdn.co/image/ab67616d0000b2736c303579cdd6c93204f090ef","uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","trackType":"spotify","codec":"ogg","seek":51114,"duration":168,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:40:16 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:16 rivo volumio[3129]: info: [1721558416034] ControllerSpotify::clearAddPlayTrack
Jul 21 12:40:16 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:40:16 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:16 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="pause track at 49934ms"
Jul 21 12:40:16 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4FtVOZM48CHrItbrqfn9Sd","play_origin":"go-librespot"}}
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:16 rivo volumio[3129]: 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}
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:16 rivo volumio[3129]: 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}
Jul 21 12:40:16 rivo volumio[3129]: verbose: CURRENT POSITION 10
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:40:16 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:16 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:16 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:16 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:16 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:16 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="loading track spotify:track:1YexFEloUaShjmXGE0iPR1 (paused: false, position: 0ms)"
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:40:16 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","play_origin":"go-librespot"}}
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1YexFEloUaShjmXGE0iPR1"
Jul 21 12:40:16 rivo go-librespot[3808]: time="2024-07-21T12:40:16+02:00" level=debug msg="requested aes key for file cd4db83ae9cd6bf9bd92968f27e9e972b3525266, gid: 1YexFEloUaShjmXGE0iPR1"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=debug msg="fetched first chunk of 19, total size is 9533808 bytes"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=info msg="loaded track \"Mwaki\" (uri: spotify:track:1YexFEloUaShjmXGE0iPR1, paused: false, position: 0ms, duration: 208135ms)"
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=debug msg="fetched chunk 1/18, size: 524288"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","name":"Mwaki","artist_names":["Zerb","Sofiya Nzau"],"album_name":"Mwaki (Major Lazer Remix)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021a6508c19c3bc140f707f319","position":0,"duration":208135,"release_date":"year:2024 month:1 day:12","track_number":3,"disc_number":1}}
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=debug msg="fetched chunk 3/18, size: 524288"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=debug msg="fetched chunk 2/18, size: 524288"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:17 rivo go-librespot[3808]: time="2024-07-21T12:40:17+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","play_origin":"go-librespot"}}
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Mwaki","artist":"Zerb, Sofiya Nzau","album":"Mwaki (Major Lazer Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021a6508c19c3bc140f707f319","uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","trackType":"spotify","seek":0,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:17 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:17 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:17 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Mwaki","artist":"Zerb, Sofiya Nzau","album":"Mwaki (Major Lazer Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021a6508c19c3bc140f707f319","uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","trackType":"spotify","seek":0,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:17 rivo volumio[3129]: verbose: CURRENT POSITION 10
Jul 21 12:40:17 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:40:17 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Mwaki","artist":"Zerb, Sofiya Nzau","album":"Mwaki (Major Lazer Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021a6508c19c3bc140f707f319","uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","trackType":"spotify","seek":0,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:17 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:17 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:17 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Mwaki","artist":"Zerb, Sofiya Nzau","album":"Mwaki (Major Lazer Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021a6508c19c3bc140f707f319","uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","trackType":"spotify","seek":0,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:17 rivo volumio[3129]: verbose: CURRENT POSITION 10
Jul 21 12:40:17 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:40:17 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:40:17 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:40:17 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:17 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:17 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:17 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:17 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:17 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:17 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:17 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:17 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:18 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:40:18 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:40:18 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:40:18 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:40:18 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:40:18 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:40:20 rivo volumio[3129]: info: CoreCommandRouter::volumioNext
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::next
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::stop
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::stPlaybackTimer
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:40:20 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:20 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:20 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:20 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::serviceStop
Jul 21 12:40:20 rivo volumio[3129]: info: CorePlayQueue::getTrack 10
Jul 21 12:40:20 rivo volumio[3129]: info: CoreCommandRouter::serviceStop
Jul 21 12:40:20 rivo volumio[3129]: info: Spotify Stop
Jul 21 12:40:20 rivo volumio[3129]: SPOTIFY: SPOTIFY STOP
Jul 21 12:40:20 rivo volumio[3129]: SPOTIFY: {"status":"play","position":10,"title":"Mwaki","artist":"Zerb","album":"Mwaki (Major Lazer Remix)","albumart":"https://i.scdn.co/image/ab67616d0000b2731a6508c19c3bc140f707f319","uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","trackType":"spotify","codec":"ogg","seek":0,"duration":208,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":66,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Jul 21 12:40:20 rivo volumio[3129]: info: Sending Spotify command to local API: /player/pause
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::play index undefined
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 12:40:20 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::startPlaybackTimer
Jul 21 12:40:20 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:20 rivo volumio[3129]: info: [1721558420420] ControllerSpotify::clearAddPlayTrack
Jul 21 12:40:20 rivo volumio[3129]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 12:40:20 rivo volumio[3129]: info: CoreStateMachine::updateTrackBlock
Jul 21 12:40:20 rivo volumio[3129]: info: CorePlayQueue::getTrackBlock
Jul 21 12:40:20 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:20 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:20 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:20 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:20 rivo go-librespot[3808]: time="2024-07-21T12:40:20+02:00" level=debug msg="pause track at 4672ms"
Jul 21 12:40:20 rivo go-librespot[3808]: time="2024-07-21T12:40:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=trace msg="emitting websocket event: paused"
Jul 21 12:40:21 rivo volumio[3129]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1YexFEloUaShjmXGE0iPR1","play_origin":"go-librespot"}}
Jul 21 12:40:21 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:21 rivo volumio[3129]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:21 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:21 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:21 rivo volumio[3129]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:21 rivo volumio[3129]: verbose: CURRENT POSITION 11
Jul 21 12:40:21 rivo volumio[3129]: info: CoreStateMachine::syncState stateService pause
Jul 21 12:40:21 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:40:21 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:21 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:21 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:21 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:21 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=debug msg="loading track spotify:track:75ckdfW23NPWGDMSjdUFBv (paused: false, position: 0ms)"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 12:40:21 rivo volumio[3129]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","play_origin":"go-librespot"}}
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:75ckdfW23NPWGDMSjdUFBv"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=debug msg="requested aes key for file 5427cf2876fb99deead33876f5bddac6c247f131, gid: 75ckdfW23NPWGDMSjdUFBv"
Jul 21 12:40:21 rivo volumio[3129]: info: camilladsp spawned new process with pid 8216, instance 1, run: true
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=debug msg="fetched first chunk of 18, total size is 8978975 bytes"
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:21 rivo go-librespot[3808]: time="2024-07-21T12:40:21+02:00" level=info msg="loaded track \"Waiting For Tonight\" (uri: spotify:track:75ckdfW23NPWGDMSjdUFBv, paused: false, position: 0ms, duration: 198019ms)"
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:21 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=trace msg="emitting websocket event: metadata"
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","name":"Waiting For Tonight","artist_names":["FISHER","Jennifer Lopez"],"album_name":"Waiting For Tonight","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021bdabe7ca53bc0b39f43b5c0","position":0,"duration":198019,"release_date":"year:2024 month:5 day:3","track_number":1,"disc_number":1}}
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=debug msg="fetched chunk 3/17, size: 524288"
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=trace msg="emitting websocket event: playing"
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","play_origin":"go-librespot"}}
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Waiting For Tonight","artist":"FISHER, Jennifer Lopez","album":"Waiting For Tonight","albumart":"https://i.scdn.co/image/ab67616d00001e021bdabe7ca53bc0b39f43b5c0","uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","trackType":"spotify","seek":0,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:22 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:22 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:22 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Waiting For Tonight","artist":"FISHER, Jennifer Lopez","album":"Waiting For Tonight","albumart":"https://i.scdn.co/image/ab67616d00001e021bdabe7ca53bc0b39f43b5c0","uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","trackType":"spotify","seek":0,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:22 rivo volumio[3129]: verbose: CURRENT POSITION 11
Jul 21 12:40:22 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:40:22 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=debug msg="fetched chunk 1/17, size: 524288"
Jul 21 12:40:22 rivo go-librespot[3808]: time="2024-07-21T12:40:22+02:00" level=debug msg="fetched chunk 2/17, size: 524288"
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: PUSH STATE SPOTIFY
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: {"status":"play","service":"spop","title":"Waiting For Tonight","artist":"FISHER, Jennifer Lopez","album":"Waiting For Tonight","albumart":"https://i.scdn.co/image/ab67616d00001e021bdabe7ca53bc0b39f43b5c0","uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","trackType":"spotify","seek":0,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:22 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Jul 21 12:40:22 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:22 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Waiting For Tonight","artist":"FISHER, Jennifer Lopez","album":"Waiting For Tonight","albumart":"https://i.scdn.co/image/ab67616d00001e021bdabe7ca53bc0b39f43b5c0","uri":"spotify:track:75ckdfW23NPWGDMSjdUFBv","trackType":"spotify","seek":0,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null}
Jul 21 12:40:22 rivo volumio[3129]: verbose: CURRENT POSITION 11
Jul 21 12:40:22 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Jul 21 12:40:22 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Jul 21 12:40:22 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Jul 21 12:40:22 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:22 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:22 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 12:40:22 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:22 rivo volumio[3129]: info: CoreStateMachine::pushState
Jul 21 12:40:22 rivo volumio[3129]: info: CorePlayQueue::getTrack 11
Jul 21 12:40:22 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - volume level for loudness 66 gain applied 0.00
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:22 rivo volumio[3129]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:22 rivo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Jul 21 12:40:23 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:40:23 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:40:23 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:40:23 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:40:23 rivo volumio[3129]: info: Executing endpoint metavolumio
Jul 21 12:40:23 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Jul 21 12:40:27 rivo volumio[3129]: error: Failed request for metavolumio API
Jul 21 12:40:28 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 21 12:40:28 rivo volumio[3129]: info: Preload queue cleared
Jul 21 12:40:29 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 21 12:40:29 rivo volumio[3129]: info: Preload queue cleared
Jul 21 12:40:30 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 21 12:40:30 rivo go-librespot[3808]: time="2024-07-21T12:40:30+02:00" level=debug msg="fetched chunk 4/17, size: 524288"
Jul 21 12:40:31 rivo volumio[3129]: info: Preload queue cleared
Jul 21 12:40:33 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 21 12:40:33 rivo volumio[3129]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 21 12:40:33 rivo volumio[3129]: TypeError: Cannot read property 'length' of undefined
Jul 21 12:40:33 rivo volumio[3129]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25
Jul 21 12:40:33 rivo volumio[3129]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13
Jul 21 12:40:33 rivo volumio[3129]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18)
Jul 21 12:40:33 rivo volumio[3129]: at Parser.emit (events.js:400:28)
Jul 21 12:40:33 rivo volumio[3129]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26)
Jul 21 12:40:33 rivo volumio[3129]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35)
Jul 21 12:40:33 rivo volumio[3129]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5)
Jul 21 12:40:33 rivo volumio[3129]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7)
Jul 21 12:40:33 rivo volumio[3129]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13)
Jul 21 12:40:33 rivo volumio[3129]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31)
Jul 21 12:40:33 rivo volumio[3129]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59)
Jul 21 12:40:33 rivo volumio[3129]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19)
Jul 21 12:40:33 rivo volumio[3129]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15)
Jul 21 12:40:33 rivo volumio[3129]: at IncomingMessage.emit (events.js:412:35)
Jul 21 12:40:33 rivo volumio[3129]: at endReadableNT (internal/streams/readable.js:1333:12)
Jul 21 12:40:33 rivo volumio[3129]: at processTicksAndRejections (internal/process/task_queues.js:82:21)
Jul 21 12:40:33 rivo volumio[3129]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 21 12:40:34 rivo sudo[8238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-21 12:39
Jul 21 12:40:34 rivo sudo[8238]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="rivo"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 09:27:25 PM CEST"
VOLUMIO_VERSION="3.703"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Rivo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Rivo"
VOLUMIO_HASH="891b8adfc94c7cc44424972b60e8e09c"