-- Logs begin at Thu 2019-02-14 12:11:58 EET, end at Fri 2025-05-30 10:55:05 EEST. -- May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPlay May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::play index 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::stop May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrackBlock May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::serviceStop May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::serviceStop May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::stop May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand stop took 8 milliseconds May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::play index undefined May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Ftrack%2Fdo-things-my-own-way@artistUrl=https%3A%2F%2Fsparksofficial.bandcamp.com@albumUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Falbum%2Fmad May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 8 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand stop took 2 milliseconds May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand playlistinfo took 40 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand clear took 39 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 11 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 9 milliseconds May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3" May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 77ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 39ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 37ms May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: touch_display: Setting screensaver timeout to 120 seconds. May 30 10:54:12 volumio volumio[960]: error: updateQueue error: null May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 36ms May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3" took 34 milliseconds May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 7ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 7ms May 30 10:54:12 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 17ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 13ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 11ms May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:12 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 6ms May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand play took 4 milliseconds May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 5ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 4 milliseconds May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: May 30 10:54:12 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 7 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Do Things My Own Way","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3","trackType":"mp3"} May 30 10:54:12 volumio volumio[960]: verbose: CURRENT POSITION 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Do Things My Own Way","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3","trackType":"mp3"} May 30 10:54:12 volumio volumio[960]: verbose: CURRENT POSITION 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:12 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 33ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 37ms May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand status took 30 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand playlistinfo took 27 milliseconds May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand playlistinfo took 26 milliseconds May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Do Things My Own Way","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3","trackType":"mp3"} May 30 10:54:12 volumio volumio[960]: verbose: CURRENT POSITION 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:12 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Do Things My Own Way","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3","trackType":"mp3"} May 30 10:54:12 volumio volumio[960]: verbose: CURRENT POSITION 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:12 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Do Things My Own Way","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3","trackType":"mp3"} May 30 10:54:12 volumio volumio[960]: verbose: CURRENT POSITION 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:12 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 80ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 79ms May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 77ms May 30 10:54:12 volumio volumio[960]: info: sendMpdCommand playlistinfo took 65 milliseconds May 30 10:54:12 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:12 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:12 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:12 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Do Things My Own Way","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/b3be7d1411b815c8dd65cf2b7de246f3/mp3-128/2495976337?p=0&ts=1748677849&t=02c00323a0eaf4615720cf48a0f7b01793dfe669&token=1748677849_e1ab7c3c986186a16b901cd976703818c6abbe96&t.mp3","trackType":"mp3"} May 30 10:54:12 volumio volumio[960]: verbose: CURRENT POSITION 0 May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:12 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:12 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:12 volumio volumio[960]: info: ------------------------------ 109ms May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPlay May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::play index 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::stop May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrackBlock May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::serviceStop May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 0 May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::serviceStop May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::stop May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand stop took 48 milliseconds May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::play index undefined May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Ftrack%2Frunning-up-a-tab-at-the-hotel-for-the-fab@artistUrl=https%3A%2F%2Fsparksofficial.bandcamp.com@albumUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Falbum%2Fmad May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 12 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: info: touch_display: Setting screensaver timeout to 120 seconds. May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 44ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 33ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 33ms May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand stop took 1 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand clear took 1 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3" May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: error: updateQueue error: null May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 6ms May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3" took 6 milliseconds May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:17 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:17 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:17 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:17 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand play took 3 milliseconds May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 4 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: May 30 10:54:17 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 11 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 9 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 9 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 8 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":262,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Running Up A Tab At The Hotel For The Fab","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3","trackType":"mp3"} May 30 10:54:17 volumio volumio[960]: verbose: CURRENT POSITION 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":262,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Running Up A Tab At The Hotel For The Fab","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3","trackType":"mp3"} May 30 10:54:17 volumio volumio[960]: verbose: CURRENT POSITION 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:17 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":262,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Running Up A Tab At The Hotel For The Fab","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3","trackType":"mp3"} May 30 10:54:17 volumio volumio[960]: verbose: CURRENT POSITION 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:17 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 37ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 54ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 54ms May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand status took 45 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 41 milliseconds May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 41 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":262,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Running Up A Tab At The Hotel For The Fab","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3","trackType":"mp3"} May 30 10:54:17 volumio volumio[960]: verbose: CURRENT POSITION 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:17 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":262,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Running Up A Tab At The Hotel For The Fab","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3","trackType":"mp3"} May 30 10:54:17 volumio volumio[960]: verbose: CURRENT POSITION 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:17 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 88ms May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 83ms May 30 10:54:17 volumio volumio[960]: info: sendMpdCommand playlistinfo took 55 milliseconds May 30 10:54:17 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:17 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:17 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:17 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":262,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Running Up A Tab At The Hotel For The Fab","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/ad2ea9ad4d94ba3b2d8c9e30a4715811/mp3-128/3414819990?p=0&ts=1748677849&t=bc0327733041189ab284e0e094085c79e2afa937&token=1748677849_dad57a991e3035935767d5501a9941b327530c9a&t.mp3","trackType":"mp3"} May 30 10:54:17 volumio volumio[960]: verbose: CURRENT POSITION 3 May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:17 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:17 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:17 volumio volumio[960]: info: ------------------------------ 123ms May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPlay May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::play index 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::stop May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrackBlock May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::serviceStop May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 3 May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::serviceStop May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::stop May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand stop took 37 milliseconds May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::play index undefined May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Ftrack%2Fin-daylight@artistUrl=https%3A%2F%2Fsparksofficial.bandcamp.com@albumUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Falbum%2Fmad May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 13 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 2 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: info: touch_display: Setting screensaver timeout to 120 seconds. May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 2 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 3 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 3 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 44ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 31ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 29ms May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand stop took 2 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand clear took 1 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3" May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: error: updateQueue error: null May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3" took 3 milliseconds May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:25 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:25 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:25 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:25 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand play took 3 milliseconds May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 7 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 4 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: May 30 10:54:25 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 11 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 4 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand status took 2 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"In Daylight","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3","trackType":"mp3"} May 30 10:54:25 volumio volumio[960]: verbose: CURRENT POSITION 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"In Daylight","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3","trackType":"mp3"} May 30 10:54:25 volumio volumio[960]: verbose: CURRENT POSITION 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:25 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"In Daylight","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3","trackType":"mp3"} May 30 10:54:25 volumio volumio[960]: verbose: CURRENT POSITION 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:25 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 43ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 48ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 49ms May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 32 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 32 milliseconds May 30 10:54:25 volumio volumio[960]: info: sendMpdCommand playlistinfo took 32 milliseconds May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":822,"duration":252,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"In Daylight","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3","trackType":"mp3"} May 30 10:54:25 volumio volumio[960]: verbose: CURRENT POSITION 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:25 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":252,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"In Daylight","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3","trackType":"mp3"} May 30 10:54:25 volumio volumio[960]: verbose: CURRENT POSITION 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:25 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:25 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:25 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":252,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"In Daylight","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/dbb07fada76c05fd6bc1b001d2c2a8bf/mp3-128/1888231874?p=0&ts=1748677849&t=8543df6f47cca874a24f2fdbfdb77021eeba3132&token=1748677849_314a64e1ff4fcc968865a5660d3fe8d2283c9e9b&t.mp3","trackType":"mp3"} May 30 10:54:25 volumio volumio[960]: verbose: CURRENT POSITION 6 May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:25 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:25 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 87ms May 30 10:54:25 volumio volumio[960]: info: ------------------------------ 78ms May 30 10:54:33 volumio volumio[960]: info: CoreCommandRouter::volumioMoveQueue May 30 10:54:33 volumio volumio[960]: info: CoreStateMachine::moveQueueItem 10 10 May 30 10:54:33 volumio volumio[960]: info: CorePlayQueue::moveQueueItem 10 --> 10 May 30 10:54:33 volumio volumio[960]: info: CoreCommandRouter::volumioPushQueue May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::volumioPlay May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::play index 8 May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::stop May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrackBlock May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::serviceStop May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 6 May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::serviceStop May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::stop May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand stop took 38 milliseconds May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::play index undefined May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Ftrack%2Fa-long-red-light@artistUrl=https%3A%2F%2Fsparksofficial.bandcamp.com@albumUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Falbum%2Fmad May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand status took 19 milliseconds May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand status took 2 milliseconds May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:34 volumio volumio[960]: info: touch_display: Setting screensaver timeout to 120 seconds. May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand playlistinfo took 3 milliseconds May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand playlistinfo took 3 milliseconds May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:34 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:34 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:34 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 52ms May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 36ms May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 34ms May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand stop took 1 milliseconds May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand clear took 1 milliseconds May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3" May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: error: updateQueue error: null May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 6ms May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3" took 5 milliseconds May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:34 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:34 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 5ms May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:34 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:34 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: May 30 10:54:34 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:34 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:34 volumio volumio[960]: info: sendMpdCommand play took 2 milliseconds May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:34 volumio volumio[960]: info: ------------------------------ 1ms May 30 10:54:35 volumio volumio[960]: info: May 30 10:54:35 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:35 volumio volumio[960]: info: May 30 10:54:35 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:35 volumio volumio[960]: info: May 30 10:54:35 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:35 volumio volumio[960]: info: May 30 10:54:35 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand status took 10 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:35 volumio volumio[960]: info: May 30 10:54:35 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:35 volumio volumio[960]: info: May 30 10:54:35 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand status took 8 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 7 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:35 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":184,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"A Long Red Light","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3","trackType":"mp3"} May 30 10:54:35 volumio volumio[960]: verbose: CURRENT POSITION 8 May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:35 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":184,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"A Long Red Light","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3","trackType":"mp3"} May 30 10:54:35 volumio volumio[960]: verbose: CURRENT POSITION 8 May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:35 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":184,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"A Long Red Light","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3","trackType":"mp3"} May 30 10:54:35 volumio volumio[960]: verbose: CURRENT POSITION 8 May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: ------------------------------ 42ms May 30 10:54:35 volumio volumio[960]: info: ------------------------------ 52ms May 30 10:54:35 volumio volumio[960]: info: ------------------------------ 46ms May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand status took 41 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand status took 39 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 36 milliseconds May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:35 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":184,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"A Long Red Light","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3","trackType":"mp3"} May 30 10:54:35 volumio volumio[960]: verbose: CURRENT POSITION 8 May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: ------------------------------ 70ms May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 36 milliseconds May 30 10:54:35 volumio volumio[960]: info: sendMpdCommand playlistinfo took 36 milliseconds May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:35 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:35 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":184,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"A Long Red Light","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3","trackType":"mp3"} May 30 10:54:35 volumio volumio[960]: verbose: CURRENT POSITION 8 May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:35 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:35 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":184,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"A Long Red Light","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/0b85dfe6d47cb430731c52996011353b/mp3-128/1618689949?p=0&ts=1748677849&t=f2be53e2c22643507ca467ce75d37a2290f06515&token=1748677849_e15c4e390b4c322229cf7669e04f8e00bd00041b&t.mp3","trackType":"mp3"} May 30 10:54:35 volumio volumio[960]: verbose: CURRENT POSITION 8 May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:35 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:35 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:35 volumio volumio[960]: info: ------------------------------ 115ms May 30 10:54:35 volumio volumio[960]: info: ------------------------------ 114ms May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPlay May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::play index 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::stop May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::stPlaybackTimer May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::updateTrackBlock May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrackBlock May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::serviceStop May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 8 May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::serviceStop May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::stop May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand stop took 41 milliseconds May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::play index undefined May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::startPlaybackTimer May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: [bandcamp-play] clearAddPlayTrack: bandcamp/track@trackUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Ftrack%2Fdrowned-in-a-sea-of-tears@artistUrl=https%3A%2F%2Fsparksofficial.bandcamp.com@albumUrl=https%3A%2F%2Fsparksofficial.bandcamp.com%2Falbum%2Fmad May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 12 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: info: touch_display: Setting screensaver timeout to 120 seconds. May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 7 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 3 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 23ms May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 7 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 7 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current bandcamp Received mpd May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 30ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 27ms May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand stop took 1 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand clear May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand clear took 2 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand addid "https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3" May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: error: updateQueue error: null May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 6ms May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand addid "https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3" took 4 milliseconds May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:38 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:38 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:38 volumio volumio[960]: verbose: MPD COMMAND [object Object] May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 6ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 3ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 2ms May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces system playlist update May 30 10:54:38 volumio volumio[960]: info: Ignoring MPD Status Update May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 4ms May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand play took 3 milliseconds May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 6ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 7ms May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 3 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 1 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: May 30 10:54:38 volumio volumio[960]: ---------------------------- MPD announces state update: player May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::getState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand status May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 6 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 7 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 6 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand status took 5 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseState May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Drowned In A Sea Of Tears","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3","trackType":"mp3"} May 30 10:54:38 volumio volumio[960]: verbose: CURRENT POSITION 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus stop May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Drowned In A Sea Of Tears","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3","trackType":"mp3"} May 30 10:54:38 volumio volumio[960]: verbose: CURRENT POSITION 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:38 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Drowned In A Sea Of Tears","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3","trackType":"mp3"} May 30 10:54:38 volumio volumio[960]: verbose: CURRENT POSITION 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:38 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 31ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 37ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 35ms May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 24 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 24 milliseconds May 30 10:54:38 volumio volumio[960]: info: sendMpdCommand playlistinfo took 24 milliseconds May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: verbose: ControllerMpd::parseTrackInfo May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Drowned In A Sea Of Tears","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3","trackType":"mp3"} May 30 10:54:38 volumio volumio[960]: verbose: CURRENT POSITION 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:38 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Drowned In A Sea Of Tears","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3","trackType":"mp3"} May 30 10:54:38 volumio volumio[960]: verbose: CURRENT POSITION 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:38 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: ControllerMpd::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::servicePushState May 30 10:54:38 volumio volumio[960]: info: CorePlayQueue::getTrack 9 May 30 10:54:38 volumio volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Drowned In A Sea Of Tears","artist":"Sparks","album":"MAD!","uri":"https://t4.bcbits.com/stream/69397ce5e158db389b8f1acf0192a433/mp3-128/3655443340?p=0&ts=1748677849&t=0d01c93a95abe6c3327fe207b519f9aab3362962&token=1748677849_93f7cf9046fefd8152a2b5d388482a41c6174e56&t.mp3","trackType":"mp3"} May 30 10:54:38 volumio volumio[960]: verbose: CURRENT POSITION 9 May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState stateService play May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::syncState currentStatus play May 30 10:54:38 volumio volumio[960]: info: Received an update from plugin. extracting info from payload May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: CoreStateMachine::pushState May 30 10:54:38 volumio volumio[960]: info: CoreCommandRouter::volumioPushState May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 76ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 74ms May 30 10:54:38 volumio volumio[960]: info: ------------------------------ 73ms May 30 10:54:57 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 30 10:54:58 volumio volumio[960]: info: Preload queue cleared May 30 10:55:00 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 30 10:55:00 volumio volumio[960]: info: Preload queue cleared May 30 10:55:04 volumio volumio[960]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 30 10:55:04 volumio volumio[960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 10:55:04 volumio volumio[960]: TypeError: Cannot read property 'length' of undefined May 30 10:55:04 volumio volumio[960]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 30 10:55:04 volumio volumio[960]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 30 10:55:04 volumio volumio[960]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 30 10:55:04 volumio volumio[960]: at Parser.emit (events.js:315:20) May 30 10:55:04 volumio volumio[960]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 30 10:55:04 volumio volumio[960]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 30 10:55:04 volumio volumio[960]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 30 10:55:04 volumio volumio[960]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 30 10:55:04 volumio volumio[960]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 30 10:55:04 volumio volumio[960]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 30 10:55:04 volumio volumio[960]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 30 10:55:04 volumio volumio[960]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 30 10:55:04 volumio volumio[960]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 30 10:55:04 volumio volumio[960]: at IncomingMessage.emit (events.js:327:22) May 30 10:55:04 volumio volumio[960]: at endReadableNT (internal/streams/readable.js:1327:12) May 30 10:55:04 volumio volumio[960]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 30 10:55:04 volumio volumio[960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 10:55:05 volumio sudo[3288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-30 10:54 May 30 10:55:05 volumio sudo[3288]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"