Dec 15 22:25:04 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:25:04 volumio volumio[12080]: info: CorePlayQueue::getTrack 2 Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::volumioNext Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::next Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::stop Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::stPlaybackTimer Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::updateTrackBlock Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrackBlock Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 2 Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::serviceStop Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 2 Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::serviceStop Dec 15 22:25:12 volumio volumio[12080]: info: [1765837512751] ControllerUPNPBrowser::stop Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand stop took 20 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::play index undefined Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::startPlaybackTimer Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: info: [1765837512774] ControllerUPNPBrowser::clearAddPlayTrack Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand stop Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::updateTrackBlock Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrackBlock Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 8 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand stop took 6 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 4 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 2 milliseconds Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand clear Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:12 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand clear took 3 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.4.242:50002/m/MP3/8174.mp3" Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Crosstown Traffic","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8177.mp3","trackType":"mp3"} Dec 15 22:25:12 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::syncState stateService stop Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus stop Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:12 volumio volumio[12080]: info: No code Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:12 volumio volumio[12080]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Dec 15 22:25:12 volumio volumio[12080]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 74ms Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 69ms Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 68ms Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:12 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:12 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:12 volumio volumio[12080]: error: updateQueue error: null Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 65ms Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:12 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:12 volumio volumio[12080]: error: updateQueue error: null Dec 15 22:25:12 volumio volumio[12080]: error: updateQueue error: null Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.4.242:50002/m/MP3/8174.mp3" Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 25ms Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 24ms Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:12 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand add "http://192.168.4.242:50002/m/MP3/8174.mp3" took 3 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand play Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:12 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:12 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 7ms Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand play took 7 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 5ms Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 3ms Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 19 milliseconds Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 23 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 22 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 7 milliseconds Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8174.mp3","artist":null,"album":null,"uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:12 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus stop Dec 15 22:25:12 volumio volumio[12080]: info: ------------------------------ 48ms Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: Dec 15 22:25:12 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 29 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 24 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 24 milliseconds Dec 15 22:25:12 volumio volumio[12080]: info: sendMpdCommand status took 12 milliseconds Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:12 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:12 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:12 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:12 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8174.mp3","artist":null,"album":null,"uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:12 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:12 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:12 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:12 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"8174.mp3","artist":null,"album":null,"uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 218ms Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 216ms Dec 15 22:25:13 volumio volumio[12080]: info: Dec 15 22:25:13 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:13 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:13 volumio volumio[12080]: info: Dec 15 22:25:13 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand status took 175 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 168 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 162 milliseconds Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 354ms Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 334ms Dec 15 22:25:13 volumio volumio[12080]: info: Dec 15 22:25:13 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:13 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:13 volumio volumio[12080]: info: Dec 15 22:25:13 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:13 volumio volumio[12080]: info: Dec 15 22:25:13 volumio volumio[12080]: ---------------------------- MPD announces system playlist update Dec 15 22:25:13 volumio volumio[12080]: info: Ignoring MPD Status Update Dec 15 22:25:13 volumio volumio[12080]: info: Dec 15 22:25:13 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 287ms Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand status took 282 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 279 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 134ms Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand status took 123 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 122ms Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand status took 118 milliseconds Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 550ms Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 93 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 98 milliseconds Dec 15 22:25:13 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 99 milliseconds Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:13 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:13 volumio volumio[12080]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:13 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState stateService play Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus play Dec 15 22:25:13 volumio volumio[12080]: info: Received an update from plugin. extracting info from payload Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 584ms Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 429ms Dec 15 22:25:13 volumio volumio[12080]: info: ------------------------------ 417ms Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:13 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:13 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:13 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:14 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:25:14 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:14 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioPause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::stPlaybackTimer Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::servicePause Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::servicePause Dec 15 22:25:16 volumio volumio[12080]: info: [1765837516785] ControllerUPNPBrowser::pause Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand pause Dec 15 22:25:16 volumio volumio[12080]: info: Dec 15 22:25:16 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand pause took 2 milliseconds Dec 15 22:25:16 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:16 volumio volumio[12080]: info: Dec 15 22:25:16 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:16 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:16 volumio volumio[12080]: info: Dec 15 22:25:16 volumio volumio[12080]: ---------------------------- MPD announces state update: player Dec 15 22:25:16 volumio volumio[12080]: info: ControllerMpd::getState Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand status Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand status took 6 milliseconds Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand status took 4 milliseconds Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand status took 5 milliseconds Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::parseState Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:16 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:16 volumio volumio[12080]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4729,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:16 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::syncState stateService pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::stPlaybackTimer Dec 15 22:25:16 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:16 volumio volumio[12080]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4729,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:16 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::syncState stateService pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::stPlaybackTimer Dec 15 22:25:16 volumio volumio[12080]: info: ------------------------------ 51ms Dec 15 22:25:16 volumio volumio[12080]: info: ------------------------------ 50ms Dec 15 22:25:16 volumio volumio[12080]: info: sendMpdCommand playlistinfo took 43 milliseconds Dec 15 22:25:16 volumio volumio[12080]: verbose: ControllerMpd::parseTrackInfo Dec 15 22:25:16 volumio volumio[12080]: info: ControllerMpd::pushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::servicePushState Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getTrack 3 Dec 15 22:25:16 volumio volumio[12080]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4729,"duration":899,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Voodoo Chile","artist":"The Jimi Hendrix Experience","album":"Electric Ladyland","uri":"http://192.168.4.242:50002/m/MP3/8174.mp3","trackType":"mp3"} Dec 15 22:25:16 volumio volumio[12080]: verbose: CURRENT POSITION 3 Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::syncState stateService pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::syncState currentStatus pause Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::pushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioPushState Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::stPlaybackTimer Dec 15 22:25:16 volumio volumio[12080]: info: ------------------------------ 69ms Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:16 volumio volumio[12080]: info: CoreCommandRouter::volumioGetQueue Dec 15 22:25:16 volumio volumio[12080]: info: CoreStateMachine::getQueue Dec 15 22:25:16 volumio volumio[12080]: info: CorePlayQueue::getQueue Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: SPOTIFY VOLUME 26 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 22:25:16 volumio volumio[12080]: SPOTIFY: DELTA VOLUME ENOUGH: false Dec 15 22:25:18 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 15 22:25:24 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:25:34 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 15 22:25:34 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 15 22:25:34 volumio systemd[1]: setdatetime-helper.service: Consumed 1.192s CPU time. Dec 15 22:25:34 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:25:34 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:34 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:44 volumio volumio[12080]: info: Preload queue cleared Dec 15 22:25:44 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:25:46 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 15 22:25:46 volumio volumio[12080]: info: CURURI: playlists Dec 15 22:25:46 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:46 volumio volumio[12080]: info: Preload queue cleared Dec 15 22:25:54 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:25:54 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:54 volumio volumio[12080]: info: Listing playlists Dec 15 22:25:56 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:25:56 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 15 22:25:56 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 15 22:25:56 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 15 22:25:56 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Dec 15 22:25:56 volumio volumio[12080]: info: Received Get System Version Dec 15 22:25:56 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 22:26:04 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:26:09 volumio volumio[12080]: info: Retrieving Cloud Streaming UI Dec 15 22:26:09 volumio volumio[12080]: info: Getting Tidal Cloud Configuration Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:26:09 volumio volumio[12080]: info: Getting Qobuz Cloud Configuration Dec 15 22:26:09 volumio volumio[12080]: info: Asking plugin for UI Config Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:26:09 volumio volumio[12080]: info: Getting Spotify Cloud Configuration Dec 15 22:26:09 volumio volumio[12080]: info: Asking plugin for UI Config Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:26:09 volumio volumio[12080]: info: Saving Spotify Acccount Dec 15 22:26:09 volumio volumio[12080]: info: Got Tidal Cloud Configuration Dec 15 22:26:09 volumio volumio[12080]: info: Got it Dec 15 22:26:09 volumio volumio[12080]: info: Got it Dec 15 22:26:09 volumio volumio[12080]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 22:26:09 volumio volumio[12080]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 22:26:09 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 22:26:12 volumio volumio[12080]: info: Enabling MyMusic plugin tidalconnect Dec 15 22:26:12 volumio volumio[12080]: info: [MyVolumio PluginManager] Enabling and starting plugin music_service tidalconnect Dec 15 22:26:12 volumio volumio[12080]: info: [MyVolumio PluginManager] Plugin music_service tidalconnect not in user plan, not enabling Dec 15 22:26:12 volumio volumio[12080]: info: Error: Plugin music_service tidalconnect not in user plan, not enabling Dec 15 22:26:12 volumio volumio[12080]: error: Could not Enable MyMusic Plugin: Error Dec 15 22:26:13 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 22:26:14 volumio volumio[12080]: info: CoreCommandRouter::volumioGetState Dec 15 22:26:14 volumio volumio[12080]: info: Listing playlists Dec 15 22:26:14 volumio volumio[12080]: info: Listing playlists Dec 15 22:26:17 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 22:26:21 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 22:26:22 volumio volumio[12080]: info: Disabling MyMusic plugin upnp Dec 15 22:26:22 volumio sudo[14178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Dec 15 22:26:22 volumio sudo[14178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 22:26:22 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Dec 15 22:26:23 volumio volumio[12080]: info: Enabling MyMusic plugin upnp Dec 15 22:26:23 volumio volumio[12080]: info: Enabling plugin upnp Dec 15 22:26:23 volumio volumio[12080]: info: Loading plugin "upnp"... Dec 15 22:26:23 volumio volumio[12080]: info: [1765837583644] Starting Upmpd Daemon Dec 15 22:26:23 volumio volumio[12080]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 22:26:23 volumio volumio[12080]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 22:26:23 volumio volumio[12080]: Error: listen EADDRINUSE: address already in use :::6599 Dec 15 22:26:23 volumio volumio[12080]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Dec 15 22:26:23 volumio volumio[12080]: at listenInCluster (node:net:1920:12) Dec 15 22:26:23 volumio volumio[12080]: at Server.listen (node:net:2008:7) Dec 15 22:26:23 volumio volumio[12080]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Dec 15 22:26:23 volumio volumio[12080]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Dec 15 22:26:23 volumio volumio[12080]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 15 22:26:23 volumio volumio[12080]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 15 22:26:23 volumio volumio[12080]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Dec 15 22:26:23 volumio volumio[12080]: code: 'EADDRINUSE', Dec 15 22:26:23 volumio volumio[12080]: errno: -98, Dec 15 22:26:23 volumio volumio[12080]: syscall: 'listen', Dec 15 22:26:23 volumio volumio[12080]: address: '::', Dec 15 22:26:23 volumio volumio[12080]: port: 6599 Dec 15 22:26:23 volumio volumio[12080]: } Dec 15 22:26:23 volumio volumio[12080]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 22:26:24 volumio sudo[14203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 22:25' Dec 15 22:26:24 volumio sudo[14203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"