-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Tue 2025-05-13 21:46:08 CEST. -- May 13 21:45:00 volumiocdl kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) May 13 21:45:00 volumiocdl volumio[1210]: info: May 13 21:45:00 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:00 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate from file: 44100 May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate from file: 44100 May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 13 21:45:00 volumiocdl volumio[1210]: info: May 13 21:45:00 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:00 volumiocdl volumio[1210]: info: sendMpdCommand status took 24 milliseconds May 13 21:45:00 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:00 volumiocdl volumio[1210]: info: sendMpdCommand status took 2 milliseconds May 13 21:45:00 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:00 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:00 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:00 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:00 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP TEMPO","artist":null,"album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:00 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:00 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:00 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus stop May 13 21:45:00 volumiocdl volumio[1210]: info: ------------------------------ 31ms May 13 21:45:00 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 3 milliseconds May 13 21:45:00 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:00 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:00 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:00 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:00 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP TEMPO","artist":null,"album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:00 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:00 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:00 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:00 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:00 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:00 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:00 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:00 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:00 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:00 volumiocdl volumio[1210]: info: ------------------------------ 29ms May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 13 21:45:00 volumiocdl volumio[1210]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:00 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:01 volumiocdl volumio[1210]: info: May 13 21:45:01 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:01 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:01 volumiocdl volumio[1210]: info: May 13 21:45:01 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:01 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:01 volumiocdl volumio[1210]: info: ------------------------------ 2ms May 13 21:45:01 volumiocdl volumio[1210]: info: sendMpdCommand status took 2 milliseconds May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:01 volumiocdl volumio[1210]: info: May 13 21:45:01 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:01 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:01 volumiocdl volumio[1210]: info: May 13 21:45:01 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:01 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:01 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:01 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:01 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:01 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":171,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Advert: - Limited Time Offer - Save on monthly, 1 Year and 2 Year Memberships - Advert:","artist":"CALMRADIO.COM - Up Tempo","album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:01 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:01 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:01 volumiocdl volumio[1210]: info: ------------------------------ 23ms May 13 21:45:01 volumiocdl volumio[1210]: info: ------------------------------ 21ms May 13 21:45:01 volumiocdl volumio[1210]: info: sendMpdCommand status took 20 milliseconds May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:01 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 4 milliseconds May 13 21:45:01 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:01 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:01 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:01 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":981,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Advert: - Limited Time Offer - Save on monthly, 1 Year and 2 Year Memberships - Advert:","artist":"CALMRADIO.COM - Up Tempo","album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:01 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:01 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:01 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:01 volumiocdl volumio[1210]: info: ------------------------------ 46ms May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:01 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:04 volumiocdl go-librespot[1389]: time="2025-05-13T21:45:04+02:00" level=trace msg="sent dealer ping" May 13 21:45:04 volumiocdl go-librespot[1389]: time="2025-05-13T21:45:04+02:00" level=trace msg="received dealer pong" May 13 21:45:11 volumiocdl volumio[1210]: info: Preload queue cleared May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::ClearQueue May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::stop May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::stPlaybackTimer May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::updateTrackBlock May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrackBlock May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::serviceStop May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::serviceStop May 13 21:45:11 volumiocdl volumio[1210]: info: [1747165511029] ControllerCalmRadio::stop May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand stop May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::clearPlayQueue May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::saveQueue May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushQueue May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::addQueueItems May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::addQueueItems May 13 21:45:11 volumiocdl volumio[1210]: info: Preload queue cleared May 13 21:45:11 volumiocdl volumio[1210]: info: Adding Item to queue: calmradio://4/534 May 13 21:45:11 volumiocdl volumio[1210]: info: Exploding uri calmradio://4/534 in service calmradio May 13 21:45:11 volumiocdl volumio[1210]: info: Calm Radio explodeUri for Cat 4 Chan 534 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushQueue May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::saveQueue May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::updateTrackBlock May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrackBlock May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPlay May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::play index 0 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::stop May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::play index undefined May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::startPlaybackTimer May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:11 volumiocdl volumio[1210]: info: [1747165511161] ControllerCalmRadio::clearAddPlayTrack May 13 21:45:11 volumiocdl volumio[1210]: { May 13 21:45:11 volumiocdl volumio[1210]: uri: 'calmradio://4/534', May 13 21:45:11 volumiocdl volumio[1210]: service: 'calmradio', May 13 21:45:11 volumiocdl volumio[1210]: trackType: 'CalmRadio', May 13 21:45:11 volumiocdl volumio[1210]: radioType: 'web', May 13 21:45:11 volumiocdl volumio[1210]: name: 'UP TEMPO', May 13 21:45:11 volumiocdl volumio[1210]: title: 'UP TEMPO', May 13 21:45:11 volumiocdl volumio[1210]: albumart: 'https://arts.calmradio.com/fapi/000/000/000/000/000/534/4de9e57687fb368fea563e7933726cabde6f7a5ff21c1849c60c4ee6ea90.png', May 13 21:45:11 volumiocdl volumio[1210]: type: 'webradio', May 13 21:45:11 volumiocdl volumio[1210]: samplerate: '', May 13 21:45:11 volumiocdl volumio[1210]: bitdepth: 0, May 13 21:45:11 volumiocdl volumio[1210]: channels: 0 May 13 21:45:11 volumiocdl volumio[1210]: } May 13 21:45:11 volumiocdl volumio[1210]: info: Calm Radio getStreamUrl for Cat 4 Chan 534 May 13 21:45:11 volumiocdl volumio[1210]: STREAMURL: https://streams.calmradio.com/api/1356/128/stream May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand stop May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:11 volumiocdl volumio[1210]: info: May 13 21:45:11 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand stop took 248 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand stop took 5 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand clear May 13 21:45:11 volumiocdl volumio[1210]: info: May 13 21:45:11 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:11 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand status took 3 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand clear took 2 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand addid "https://streams.calmradio.com/api/1356/128/stream" May 13 21:45:11 volumiocdl volumio[1210]: error: updateQueue error: null May 13 21:45:11 volumiocdl volumio[1210]: info: May 13 21:45:11 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:11 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:11 volumiocdl volumio[1210]: info: ------------------------------ 3ms May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand addid "https://streams.calmradio.com/api/1356/128/stream" took 2 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:11 volumiocdl volumio[1210]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 13 21:45:11 volumiocdl volumio[1210]: verbose: MPD COMMAND [object Object] May 13 21:45:11 volumiocdl volumio[1210]: info: ------------------------------ 8ms May 13 21:45:11 volumiocdl volumio[1210]: info: May 13 21:45:11 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:11 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:11 volumiocdl volumio[1210]: info: ------------------------------ 3ms May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService mpd May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand play May 13 21:45:11 volumiocdl volumio[1210]: info: ------------------------------ 1ms May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand play took 1 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: info: May 13 21:45:11 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:11 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:11 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 13 21:45:11 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate from file: 44100 May 13 21:45:11 volumiocdl volumio[1210]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 13 21:45:11 volumiocdl volumio[1210]: info: May 13 21:45:11 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand status took 16 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand status took 1 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:11 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:11 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP TEMPO","artist":null,"album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:11 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus stop May 13 21:45:11 volumiocdl volumio[1210]: info: ------------------------------ 21ms May 13 21:45:11 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:11 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:11 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:11 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:11 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP TEMPO","artist":null,"album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:11 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:11 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:11 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:11 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:11 volumiocdl volumio[1210]: info: ------------------------------ 20ms May 13 21:45:11 volumiocdl volumio[1210]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:11 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:11 volumiocdl kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) May 13 21:45:12 volumiocdl volumio[1210]: info: May 13 21:45:12 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:12 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:12 volumiocdl volumio[1210]: info: May 13 21:45:12 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:12 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:12 volumiocdl volumio[1210]: info: May 13 21:45:12 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:12 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:12 volumiocdl volumio[1210]: info: May 13 21:45:12 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:12 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:12 volumiocdl volumio[1210]: info: ------------------------------ 5ms May 13 21:45:12 volumiocdl volumio[1210]: info: sendMpdCommand status took 4 milliseconds May 13 21:45:12 volumiocdl volumio[1210]: info: ------------------------------ 3ms May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:12 volumiocdl volumio[1210]: info: sendMpdCommand status took 3 milliseconds May 13 21:45:12 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 1 milliseconds May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:12 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:12 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":981,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Advert: - Limited Time Offer - Save on monthly, 1 Year and 2 Year Memberships - Advert:","artist":"CALMRADIO.COM - Up Tempo","album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:12 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:12 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:12 volumiocdl volumio[1210]: info: ------------------------------ 26ms May 13 21:45:12 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 20 milliseconds May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:12 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:12 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1175,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Advert: - Limited Time Offer - Save on monthly, 1 Year and 2 Year Memberships - Advert:","artist":"CALMRADIO.COM - Up Tempo","album":null,"uri":"https://streams.calmradio.com/api/1356/128/stream","trackType":""} May 13 21:45:12 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:12 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:12 volumiocdl volumio[1210]: info: ------------------------------ 42ms May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:12 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:12 volumiocdl volumio[1210]: info: Preload queue cleared May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioReplaceandPlayItems May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::ClearQueue May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::stop May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::stPlaybackTimer May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::updateTrackBlock May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrackBlock May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::serviceStop May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::serviceStop May 13 21:45:12 volumiocdl volumio[1210]: info: [1747165512860] ControllerCalmRadio::stop May 13 21:45:12 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand stop May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::clearPlayQueue May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::saveQueue May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushQueue May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::addQueueItems May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::addQueueItems May 13 21:45:12 volumiocdl volumio[1210]: info: Preload queue cleared May 13 21:45:12 volumiocdl volumio[1210]: info: Adding Item to queue: calmradio://4/556 May 13 21:45:12 volumiocdl volumio[1210]: info: Exploding uri calmradio://4/556 in service calmradio May 13 21:45:12 volumiocdl volumio[1210]: info: Calm Radio explodeUri for Cat 4 Chan 556 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushQueue May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::saveQueue May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::updateTrackBlock May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrackBlock May 13 21:45:12 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPlay May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::play index 0 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::stop May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::play index undefined May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:12 volumiocdl volumio[1210]: info: CoreStateMachine::startPlaybackTimer May 13 21:45:12 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:12 volumiocdl volumio[1210]: info: [1747165512987] ControllerCalmRadio::clearAddPlayTrack May 13 21:45:12 volumiocdl volumio[1210]: { May 13 21:45:12 volumiocdl volumio[1210]: uri: 'calmradio://4/556', May 13 21:45:12 volumiocdl volumio[1210]: service: 'calmradio', May 13 21:45:12 volumiocdl volumio[1210]: trackType: 'CalmRadio', May 13 21:45:12 volumiocdl volumio[1210]: radioType: 'web', May 13 21:45:12 volumiocdl volumio[1210]: name: 'ZONE OUT', May 13 21:45:12 volumiocdl volumio[1210]: title: 'ZONE OUT', May 13 21:45:12 volumiocdl volumio[1210]: albumart: 'https://arts.calmradio.com/fapi/000/000/000/000/000/556/6f6832dd8970a3f130ab00835b3aff82e3fb2070ebe52eaa3018ac16a25e.png', May 13 21:45:12 volumiocdl volumio[1210]: type: 'webradio', May 13 21:45:12 volumiocdl volumio[1210]: samplerate: '', May 13 21:45:12 volumiocdl volumio[1210]: bitdepth: 0, May 13 21:45:12 volumiocdl volumio[1210]: channels: 0 May 13 21:45:12 volumiocdl volumio[1210]: } May 13 21:45:12 volumiocdl volumio[1210]: info: Calm Radio getStreamUrl for Cat 4 Chan 556 May 13 21:45:13 volumiocdl volumio[1210]: STREAMURL: https://streams.calmradio.com/api/1812/128/stream May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand stop May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand stop took 244 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand stop took 9 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand clear May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:13 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand status took 7 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand clear took 6 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand addid "https://streams.calmradio.com/api/1812/128/stream" May 13 21:45:13 volumiocdl volumio[1210]: error: updateQueue error: null May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:13 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 6ms May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 4 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand addid "https://streams.calmradio.com/api/1812/128/stream" took 4 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:13 volumiocdl volumio[1210]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 13 21:45:13 volumiocdl volumio[1210]: verbose: MPD COMMAND [object Object] May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 15ms May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:13 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 6ms May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService mpd May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand play May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 3ms May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand play took 2 milliseconds May 13 21:45:13 volumiocdl kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:13 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:13 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 13 21:45:13 volumiocdl volumio[1210]: info: FusionDsp - ---- read samplerate from file: 44100 May 13 21:45:13 volumiocdl volumio[1210]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand status took 13 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand status took 2 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:13 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:13 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:13 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:13 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ZONE OUT","artist":null,"album":null,"uri":"https://streams.calmradio.com/api/1812/128/stream","trackType":""} May 13 21:45:13 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus stop May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 21ms May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 4 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:13 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:13 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:13 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:13 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ZONE OUT","artist":null,"album":null,"uri":"https://streams.calmradio.com/api/1812/128/stream","trackType":""} May 13 21:45:13 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:13 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:13 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:13 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:13 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:13 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 25ms May 13 21:45:13 volumiocdl volumio[1210]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:13 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces system playlist update May 13 21:45:13 volumiocdl volumio[1210]: info: Ignoring MPD Status Update May 13 21:45:13 volumiocdl volumio[1210]: info: May 13 21:45:13 volumiocdl volumio[1210]: ---------------------------- MPD announces state update: player May 13 21:45:13 volumiocdl volumio[1210]: info: ControllerMpd::getState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand status May 13 21:45:13 volumiocdl volumio[1210]: info: ------------------------------ 3ms May 13 21:45:13 volumiocdl volumio[1210]: info: sendMpdCommand status took 1 milliseconds May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::parseState May 13 21:45:13 volumiocdl volumio[1210]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 21:45:14 volumiocdl volumio[1210]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 21:45:14 volumiocdl volumio[1210]: verbose: ControllerMpd::parseTrackInfo May 13 21:45:14 volumiocdl volumio[1210]: info: ControllerMpd::pushState May 13 21:45:14 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePushState May 13 21:45:14 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:14 volumiocdl volumio[1210]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1106,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"LUCHS - Chasing Cloud Nine - EP - Reverie","artist":"ZONE OUT - sampler","album":null,"uri":"https://streams.calmradio.com/api/1812/128/stream","trackType":""} May 13 21:45:14 volumiocdl volumio[1210]: verbose: CURRENT POSITION 0 May 13 21:45:14 volumiocdl volumio[1210]: info: CoreStateMachine::syncState stateService play May 13 21:45:14 volumiocdl volumio[1210]: info: CoreStateMachine::syncState currentStatus play May 13 21:45:14 volumiocdl volumio[1210]: info: Received an update from plugin. extracting info from payload May 13 21:45:14 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:14 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:45:14 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:14 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:45:14 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:45:14 volumiocdl volumio[1210]: info: ------------------------------ 21ms May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: SPOTIFY VOLUME 40 May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: VOLUMIO VOLUME 41 May 13 21:45:14 volumiocdl volumio[1210]: SPOTIFY: DELTA VOLUME ENOUGH: false May 13 21:45:25 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 13 21:45:25 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 13 21:45:26 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 13 21:45:26 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 21:45:26 volumiocdl volumio[1210]: info: Discovery: Getting this device information May 13 21:45:26 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioGetState May 13 21:45:26 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 21:45:33 volumiocdl volumio[1210]: info: Starting Uninstall of plugin music_service - calmradio May 13 21:45:33 volumiocdl volumio[1210]: info: Uninstalling plugin calmradio May 13 21:45:33 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioRemoveToBrowseSourcescalmradio May 13 21:45:33 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 21:45:33 volumiocdl volumio[1210]: Cannot find translation for source Calm Radio May 13 21:45:33 volumiocdl volumio[1210]: Cannot find translation for source Spotify May 13 21:45:34 volumiocdl volumio[1210]: info: Disabling plugin calmradio May 13 21:45:34 volumiocdl volumio[1210]: info: Checking if uninstall.sh is present May 13 21:45:34 volumiocdl volumio[1210]: info: Executing uninstall.sh May 13 21:45:34 volumiocdl sudo[2613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/calmradio/uninstall.sh May 13 21:45:34 volumiocdl sudo[2613]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 21:45:34 volumiocdl sudo[2613]: pam_unix(sudo:session): session closed for user root May 13 21:45:34 volumiocdl volumio[1210]: info: Uninstall script completed May 13 21:45:34 volumiocdl volumio[1210]: info: Removing plugin calmradio from configuration May 13 21:45:34 volumiocdl volumio[1210]: info: Successfully removed calmradio configuration files May 13 21:45:34 volumiocdl volumio[1210]: info: Plugin folders cleanup May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning into folder /volumio/app/plugins/ May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category audio_interface May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category miscellanea May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category music_service May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category plugins.json May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category system_controller May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category user_interface May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning into folder /data/plugins/ May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category audio_interface May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category music_service May 13 21:45:34 volumiocdl volumio[1210]: info: Cleaning folder for calmradio May 13 21:45:34 volumiocdl volumio[1210]: info: Scanning category system_controller May 13 21:45:34 volumiocdl volumio[1210]: info: Plugin folders cleanup completed May 13 21:45:34 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 13 21:45:34 volumiocdl volumio[1210]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.61","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":true,"enabled":true,"active":true},{"prettyName":"Mpd http & Icecast output","name":"mpdoutput","category":"audio_interface","version":"1.0.5","icon":"fa-music","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"miniDLNA","name":"minidlna","category":"music_service","version":"3.1.12","icon":"fa-share-alt","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.4","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"AutoStart","name":"autostart","category":"system_controller","version":"3.0.4","icon":"fa-lightbulb-o","isManuallyInstalled":false,"enabled":true,"active":true}] May 13 21:45:34 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 13 21:45:34 volumiocdl go-librespot[1389]: time="2025-05-13T21:45:34+02:00" level=trace msg="received accesspoint ping" May 13 21:45:34 volumiocdl go-librespot[1389]: time="2025-05-13T21:45:34+02:00" level=trace msg="received accesspoint pong ack" May 13 21:45:34 volumiocdl go-librespot[1389]: time="2025-05-13T21:45:34+02:00" level=trace msg="sent dealer ping" May 13 21:45:34 volumiocdl go-librespot[1389]: time="2025-05-13T21:45:34+02:00" level=trace msg="received dealer pong" May 13 21:45:41 volumiocdl volumio[1210]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 21:45:48 volumiocdl volumio[1210]: info: CALLMETHOD: audio_interface mpdoutput eicestream May 13 21:45:48 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: mpdoutput , eicestream May 13 21:45:48 volumiocdl volumio[1210]: info: mpdhttpout ---TRUE May 13 21:45:48 volumiocdl volumio[1210]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. May 13 21:45:48 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioGetState May 13 21:45:48 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPause May 13 21:45:48 volumiocdl volumio[1210]: info: CoreStateMachine::pause May 13 21:45:48 volumiocdl volumio[1210]: info: CoreStateMachine::stPlaybackTimer May 13 21:45:48 volumiocdl volumio[1210]: info: CoreStateMachine::servicePause May 13 21:45:48 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:45:48 volumiocdl volumio[1210]: info: CoreCommandRouter::servicePause May 13 21:45:48 volumiocdl volumio[1210]: error: WARNING: No pause method for service calmradio May 13 21:45:48 volumiocdl volumio[1210]: info: mpdhttpout --- Volumio set on pause May 13 21:45:50 volumiocdl volumio[1210]: info: CoreCommandRouter::getUIConfigOnPlugin May 13 21:45:51 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 13 21:45:51 volumiocdl sudo[2653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 21:45:51 volumiocdl sudo[2653]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 21:45:51 volumiocdl systemd[1]: Stopping Music Player Daemon... May 13 21:45:51 volumiocdl systemd[1]: mpd.service: Succeeded. May 13 21:45:51 volumiocdl systemd[1]: Stopped Music Player Daemon. May 13 21:45:51 volumiocdl systemd[1]: Starting Music Player Daemon... May 13 21:45:51 volumiocdl sudo[2655]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 21:45:51 volumiocdl sudo[2655]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 21:45:51 volumiocdl sudo[2655]: pam_unix(sudo:session): session closed for user root May 13 21:45:51 volumiocdl kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) May 13 21:45:51 volumiocdl mpd[2658]: May 13 21:45 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 21:45:51 volumiocdl systemd[1]: Started Music Player Daemon. May 13 21:45:51 volumiocdl sudo[2653]: pam_unix(sudo:session): session closed for user root May 13 21:45:51 volumiocdl volumio[1210]: error: updateQueue error: null May 13 21:45:56 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 13 21:45:56 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 21:45:56 volumiocdl volumio[1210]: info: Discovery: Getting this device information May 13 21:45:56 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioGetState May 13 21:45:56 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 21:46:04 volumiocdl go-librespot[1389]: time="2025-05-13T21:46:04+02:00" level=trace msg="sent dealer ping" May 13 21:46:04 volumiocdl go-librespot[1389]: time="2025-05-13T21:46:04+02:00" level=trace msg="received dealer pong" May 13 21:46:08 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioRemoveQueueItem May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::removeQueueItem May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::stop May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::updateTrackBlock May 13 21:46:08 volumiocdl volumio[1210]: info: CorePlayQueue::getTrackBlock May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::stPlaybackTimer May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::pushState May 13 21:46:08 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:46:08 volumiocdl volumio[1210]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 21:46:08 volumiocdl volumio[1210]: info: CoreCommandRouter::volumioPushState May 13 21:46:08 volumiocdl volumio[1210]: info: CoreStateMachine::serviceStop May 13 21:46:08 volumiocdl volumio[1210]: info: CorePlayQueue::getTrack 0 May 13 21:46:08 volumiocdl volumio[1210]: info: CoreCommandRouter::serviceStop May 13 21:46:08 volumiocdl volumio[1210]: error: WARNING: No stop method for service calmradio May 13 21:46:08 volumiocdl volumio[1210]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 21:46:08 volumiocdl volumio[1210]: TypeError: Cannot read property 'then' of undefined May 13 21:46:08 volumiocdl volumio[1210]: at CoreStateMachine.removeQueueItem (/volumio/app/statemachine.js:1368:7) May 13 21:46:08 volumiocdl volumio[1210]: at CoreCommandRouter.volumioRemoveQueueItem (/volumio/app/index.js:121:28) May 13 21:46:08 volumiocdl volumio[1210]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:173:33) May 13 21:46:08 volumiocdl volumio[1210]: at Socket.emit (events.js:315:20) May 13 21:46:08 volumiocdl volumio[1210]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 13 21:46:08 volumiocdl volumio[1210]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 13 21:46:08 volumiocdl volumio[1210]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 21:46:08 volumiocdl sudo[2736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 21:45 May 13 21:46:08 volumiocdl sudo[2736]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:47:57 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fddd10196af80fdc784c726185a6abe4"