-- Logs begin at Sun 2025-05-18 16:55:19 CST, end at Sun 2025-05-18 17:40:56 CST. -- May 18 17:39:01 volumio volumio[9657]: info: Clearing queue after UPNP request May 18 17:39:02 volumio volumio[9657]: info: CoreStateMachine::ClearQueue May 18 17:39:02 volumio volumio[9657]: info: CoreStateMachine::stop May 18 17:39:02 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 17:39:02 volumio volumio[9657]: info: CorePlayQueue::clearPlayQueue May 18 17:39:02 volumio volumio[9657]: info: CorePlayQueue::saveQueue May 18 17:39:02 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:02 volumio volumio[9657]: info: CoreCommandRouter::volumioPushQueue May 18 17:39:02 volumio volumio[9657]: error: Upnp client error: Error: This socket has been ended by the other party May 18 17:39:03 volumio volumio[9657]: info: Starting UPNP Playback May 18 17:39:03 volumio volumio[9657]: info: Preparing playback through UPNP May 18 17:39:03 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:03 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:39:03 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 3ms May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:04 volumio volumio[9657]: info: sendMpdCommand status took 5 milliseconds May 18 17:39:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:04 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:39:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":285,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"王晴 - 秋来秋去 (又名：秋去秋来)","artist":"王晴","album":null,"uri":"http://fsandroid.kugou.com/202505181739/b170ceaa2b4d7cdaff5613d3868b6662/v3/72a76e207b3d82793f79df1807155aef/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx554614837_quviper_tape_s272348038.mp3","trackType":"mp3"} May 18 17:39:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 7ms May 18 17:39:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":285,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"王晴 - 秋来秋去 (又名：秋去秋来)","artist":"王晴","album":null,"uri":"http://fsandroid.kugou.com/202505181739/b170ceaa2b4d7cdaff5613d3868b6662/v3/72a76e207b3d82793f79df1807155aef/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx554614837_quviper_tape_s272348038.mp3","trackType":"mp3"} May 18 17:39:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 12ms May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:04 volumio volumio[9657]: info: May 18 17:39:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 4ms May 18 17:39:04 volumio volumio[9657]: info: sendMpdCommand status took 4 milliseconds May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 17:39:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":285,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"秋来秋去（又名：秋去秋来）","artist":"王晴","album":"秋来秋去（又名：秋去秋来）","uri":"http://fsandroid.kugou.com/202505181739/b170ceaa2b4d7cdaff5613d3868b6662/v3/72a76e207b3d82793f79df1807155aef/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx554614837_quviper_tape_s272348038.mp3","trackType":"mp3"} May 18 17:39:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:04 volumio volumio[9657]: info: ------------------------------ 18ms May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:08 volumio volumio[9657]: info: May 18 17:39:08 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:08 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:08 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:08 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:39:08 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:08 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:08 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 17:39:08 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:08 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:08 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:08 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:08 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:08 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:39:08 volumio volumio[9657]: 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":"秋来秋去（又名：秋去秋来）","artist":"王晴","album":"秋来秋去（又名：秋去秋来）","uri":"http://fsandroid.kugou.com/202505181739/b170ceaa2b4d7cdaff5613d3868b6662/v3/72a76e207b3d82793f79df1807155aef/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx554614837_quviper_tape_s272348038.mp3","trackType":"mp3"} May 18 17:39:08 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:08 volumio volumio[9657]: info: CoreStateMachine::syncState stateService stop May 18 17:39:08 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:08 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:08 volumio volumio[9657]: info: CoreStateMachine::stPlaybackTimer May 18 17:39:08 volumio volumio[9657]: info: ------------------------------ 13ms May 18 17:39:08 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:08 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:08 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:08 volumio volumio[9657]: info: Clearing queue after UPNP request May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::ClearQueue May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::stop May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 17:39:09 volumio volumio[9657]: info: CorePlayQueue::clearPlayQueue May 18 17:39:09 volumio volumio[9657]: info: CorePlayQueue::saveQueue May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushQueue May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: error: updateQueue error: null May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:39:09 volumio volumio[9657]: info: Starting UPNP Playback May 18 17:39:09 volumio volumio[9657]: info: Preparing playback through UPNP May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:09 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 17:39:09 volumio volumio[9657]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 18 17:39:09 volumio volumio[9657]: info: Retrying Login Due to Network Error May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 3ms May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:09 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:09 volumio volumio[9657]: info: sendMpdCommand status took 2 milliseconds May 18 17:39:09 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:09 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:39:09 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:09 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:09 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:09 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":398,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hamidshax - Excuse Me","artist":"Hamidshax","album":null,"uri":"http://fsandroid.kugou.com/202505181739/3f969312dc71198c288fea44d7f7fee1/v3/096804fe7a7acbf6f294133450a63f90/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx561068135_quviper_tape_s556920067.mp3","trackType":"mp3"} May 18 17:39:09 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 5ms May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:09 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:09 volumio volumio[9657]: info: May 18 17:39:09 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:09 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 17:39:09 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:09 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:09 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:09 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":398,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Hamidshax - Excuse Me","artist":"Hamidshax","album":null,"uri":"http://fsandroid.kugou.com/202505181739/3f969312dc71198c288fea44d7f7fee1/v3/096804fe7a7acbf6f294133450a63f90/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx561068135_quviper_tape_s556920067.mp3","trackType":"mp3"} May 18 17:39:09 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:09 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 16ms May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 13ms May 18 17:39:09 volumio volumio[9657]: info: sendMpdCommand status took 13 milliseconds May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:09 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 17:39:09 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:09 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:09 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:09 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":398,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Excuse Me","artist":"Hamidshax","album":"Excuse Me","uri":"http://fsandroid.kugou.com/202505181739/3f969312dc71198c288fea44d7f7fee1/v3/096804fe7a7acbf6f294133450a63f90/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx561068135_quviper_tape_s556920067.mp3","trackType":"mp3"} May 18 17:39:09 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:09 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:09 volumio volumio[9657]: info: ------------------------------ 34ms May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:09 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:09 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:09 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:09 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:19 volumio volumio[9657]: info: MyVolumio login type: Token May 18 17:39:47 volumio sudo[18563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 18 17:39:47 volumio sudo[18563]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:39:47 volumio sudo[18563]: pam_unix(sudo:session): session closed for user root May 18 17:39:47 volumio sudo[18566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 18 17:39:47 volumio sudo[18566]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:39:47 volumio sudo[18566]: pam_unix(sudo:session): session closed for user root May 18 17:39:47 volumio volumio[9657]: verbose: New Socket.io Connection to 192.168.3.160 from 192.168.3.74 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 8 May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::volumioGetVisibleSources May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 18 17:39:47 volumio volumio[9657]: info: Received Get System Info May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 17:39:47 volumio volumio[9657]: info: Discovery: Getting this device information May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:47 volumio volumio[9657]: info: Listing playlists May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 18 17:39:47 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 18 17:39:48 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:49 volumio volumio[9657]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 18 17:39:49 volumio volumio[9657]: info: Retrying Login Due to Network Error May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 18 17:39:49 volumio volumio[9657]: info: Received Get System Info May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 17:39:49 volumio volumio[9657]: info: Discovery: Getting this device information May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 17:39:49 volumio volumio[9657]: info: May 18 17:39:49 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:49 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:49 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:49 volumio volumio[9657]: info: sendMpdCommand status took 0 milliseconds May 18 17:39:49 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:49 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:49 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:39:49 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:49 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:49 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:49 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:39:49 volumio volumio[9657]: 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":"Excuse Me","artist":"Hamidshax","album":"Excuse Me","uri":"http://fsandroid.kugou.com/202505181739/3f969312dc71198c288fea44d7f7fee1/v3/096804fe7a7acbf6f294133450a63f90/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx561068135_quviper_tape_s556920067.mp3","trackType":"mp3"} May 18 17:39:49 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:49 volumio volumio[9657]: info: CoreStateMachine::syncState stateService stop May 18 17:39:49 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:49 volumio volumio[9657]: info: CoreStateMachine::stPlaybackTimer May 18 17:39:49 volumio volumio[9657]: info: ------------------------------ 12ms May 18 17:39:49 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:49 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:49 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:50 volumio volumio[9657]: info: Clearing queue after UPNP request May 18 17:39:50 volumio volumio[9657]: info: CoreStateMachine::ClearQueue May 18 17:39:50 volumio volumio[9657]: info: CoreStateMachine::stop May 18 17:39:50 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 17:39:50 volumio volumio[9657]: info: CorePlayQueue::clearPlayQueue May 18 17:39:50 volumio volumio[9657]: info: CorePlayQueue::saveQueue May 18 17:39:50 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:50 volumio volumio[9657]: info: CoreCommandRouter::volumioPushQueue May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: error: updateQueue error: null May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 0ms May 18 17:39:50 volumio volumio[9657]: info: Starting UPNP Playback May 18 17:39:50 volumio volumio[9657]: info: Preparing playback through UPNP May 18 17:39:50 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:39:50 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:39:50 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 0ms May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 0ms May 18 17:39:50 volumio volumio[9657]: info: May 18 17:39:50 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:50 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:50 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:39:51 volumio volumio[9657]: info: May 18 17:39:51 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:51 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:51 volumio volumio[9657]: info: May 18 17:39:51 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:51 volumio volumio[9657]: info: sendMpdCommand status took 3 milliseconds May 18 17:39:51 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:51 volumio volumio[9657]: info: sendMpdCommand status took 2 milliseconds May 18 17:39:51 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:51 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:51 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:51 volumio volumio[9657]: 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":"Fatrik - Just Be","artist":"Fatrik","album":null,"uri":"http://fsandroid.kugou.com/202505181739/8bf74a77c85ff81cc62cb9463213ee49/v3/332e473cbcfe48d62be10731dbe0fc19/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx369057195_quviper_tape_s3852657454.mp3","trackType":"mp3"} May 18 17:39:51 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:39:51 volumio volumio[9657]: info: ------------------------------ 7ms May 18 17:39:51 volumio volumio[9657]: info: May 18 17:39:51 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:39:51 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:39:51 volumio volumio[9657]: info: May 18 17:39:51 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:39:51 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 17:39:51 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:51 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:51 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:51 volumio volumio[9657]: 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":"Fatrik - Just Be","artist":"Fatrik","album":null,"uri":"http://fsandroid.kugou.com/202505181739/8bf74a77c85ff81cc62cb9463213ee49/v3/332e473cbcfe48d62be10731dbe0fc19/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx369057195_quviper_tape_s3852657454.mp3","trackType":"mp3"} May 18 17:39:51 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:51 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:51 volumio volumio[9657]: info: ------------------------------ 23ms May 18 17:39:51 volumio volumio[9657]: info: ------------------------------ 19ms May 18 17:39:51 volumio volumio[9657]: info: sendMpdCommand status took 19 milliseconds May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:39:51 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 17:39:51 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:39:51 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:39:51 volumio volumio[9657]: verbose: In UPNP mode May 18 17:39:51 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":221,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Just Be","artist":"Fatrik","album":"Gangnam Classic","uri":"http://fsandroid.kugou.com/202505181739/8bf74a77c85ff81cc62cb9463213ee49/v3/332e473cbcfe48d62be10731dbe0fc19/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx369057195_quviper_tape_s3852657454.mp3","trackType":"mp3"} May 18 17:39:51 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:39:51 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:39:51 volumio volumio[9657]: info: ------------------------------ 43ms May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:51 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:51 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:39:51 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:39:51 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 17:39:54 volumio volumio[9657]: Invalid card number. May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 18 17:39:54 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 18 17:39:57 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 18 17:39:59 volumio volumio[9657]: info: MyVolumio login type: Token May 18 17:40:00 volumio volumio[9657]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 18 17:40:00 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 18 17:40:00 volumio volumio[9657]: info: Preparing to save Alsa Options, stopping services first May 18 17:40:00 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:40:00 volumio volumio[9657]: info: CoreCommandRouter::volumioPause May 18 17:40:00 volumio volumio[9657]: info: CoreStateMachine::pause May 18 17:40:00 volumio volumio[9657]: info: CoreStateMachine::stPlaybackTimer May 18 17:40:00 volumio volumio[9657]: info: CoreStateMachine::servicePause May 18 17:40:00 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:00 volumio volumio[9657]: info: Error: no service or no trackblock to pause May 18 17:40:00 volumio volumio[9657]: info: Saving Audio Output to: {"output_device":{"value":"7","label":"Dummy"}} May 18 17:40:00 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 17:40:00 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 17:40:00 volumio volumio[9657]: info: Setting mixer Master for card Dummy May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 18 17:40:01 volumio volumio[9657]: info: Updating Volume Controller Parameters: Device: 7 Name: Dummy Mixer: Master Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 18 17:40:01 volumio volumio[9657]: info: Disabling external Volume Control May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:01 volumio volumio[9657]: info: Preparing to generate the ALSA configuration file May 18 17:40:01 volumio volumio[9657]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf May 18 17:40:01 volumio volumio[9657]: info: Reading ALSA contributions from plugins. May 18 17:40:01 volumio volumio[9657]: Unable to parse: May 18 17:40:01 volumio volumio[9657]: Simple mixer control 'Master',0 May 18 17:40:01 volumio volumio[9657]: Capabilities: volume cswitch May 18 17:40:01 volumio volumio[9657]: Playback channels: Front Left - Front Right May 18 17:40:01 volumio volumio[9657]: Capture channels: Front Left - Front Right May 18 17:40:01 volumio volumio[9657]: Limits: -50 - 100 May 18 17:40:01 volumio volumio[9657]: Front Left: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:01 volumio volumio[9657]: Front Right: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:01 volumio volumio[9657]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 18 17:40:01 volumio volumio[9657]: Unable to parse: May 18 17:40:01 volumio volumio[9657]: Simple mixer control 'Master',0 May 18 17:40:01 volumio volumio[9657]: Capabilities: volume cswitch May 18 17:40:01 volumio volumio[9657]: Playback channels: Front Left - Front Right May 18 17:40:01 volumio volumio[9657]: Capture channels: Front Left - Front Right May 18 17:40:01 volumio volumio[9657]: Limits: -50 - 100 May 18 17:40:01 volumio volumio[9657]: Front Left: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:01 volumio volumio[9657]: Front Right: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:01 volumio volumio[9657]: info: VolumeController:: Volume=undefined Mute =false May 18 17:40:01 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:01 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:01 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:01 volumio volumio[9657]: info: Asound.conf file written May 18 17:40:01 volumio sudo[18752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 18 17:40:01 volumio sudo[18752]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio sudo[18752]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting MPD May 18 17:40:01 volumio sudo[18757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 18 17:40:01 volumio sudo[18757]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio sudo[18757]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio sudo[18760]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 18 17:40:01 volumio sudo[18760]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio systemd[1]: Stopping Music Player Daemon... May 18 17:40:01 volumio volumio[9657]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio systemd[1]: mpd.service: Succeeded. May 18 17:40:01 volumio systemd[1]: Stopped Music Player Daemon. May 18 17:40:01 volumio volumio[9657]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting MPD May 18 17:40:01 volumio systemd[1]: Starting Music Player Daemon... May 18 17:40:01 volumio sudo[18773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio sudo[18773]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio sudo[18773]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio sudo[18775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 18 17:40:01 volumio sudo[18775]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 18 17:40:01 volumio systemd[1]: mpd.service: Succeeded. May 18 17:40:01 volumio systemd[1]: Stopped Music Player Daemon. May 18 17:40:01 volumio systemd[1]: Starting Music Player Daemon... May 18 17:40:01 volumio volumio[9657]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 17:40:01 volumio volumio[9657]: info: Output device has changed, restarting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio sudo[18781]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 18 17:40:01 volumio sudo[18781]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio sudo[18781]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 18 17:40:01 volumio volumio[9657]: info: MPD Permissions set May 18 17:40:01 volumio volumio[9657]: info: MPD Permissions set May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 18 17:40:01 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 18 17:40:01 volumio volumio[9657]: info: Starting Shairport Sync May 18 17:40:01 volumio volumio[9657]: info: Starting Shairport Sync May 18 17:40:01 volumio sudo[18804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 17:40:01 volumio sudo[18804]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio volumio[9657]: info: Starting Shairport Sync May 18 17:40:01 volumio sudo[18806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 17:40:01 volumio sudo[18806]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 17:40:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio volumio[9657]: info: Starting Shairport Sync May 18 17:40:01 volumio sudo[18810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 17:40:01 volumio sudo[18810]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio sudo[18804]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: info: Starting Shairport Sync May 18 17:40:01 volumio sudo[18806]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 17:40:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio sudo[18814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 17:40:01 volumio sudo[18814]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio volumio[9657]: info: Starting Shairport Sync May 18 17:40:01 volumio sudo[18810]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 17:40:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio sudo[18817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 17:40:01 volumio sudo[18817]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio sudo[18814]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Succeeded. May 18 17:40:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio volumio[9657]: info: Shairport-Sync Started May 18 17:40:01 volumio volumio[9657]: info: Shairport-Sync Started May 18 17:40:01 volumio volumio[9657]: info: Shairport-Sync Started May 18 17:40:01 volumio volumio[9657]: info: Shairport-Sync Started May 18 17:40:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio sudo[18823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 18 17:40:01 volumio sudo[18823]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:01 volumio sudo[18817]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: info: Shairport-Sync Started May 18 17:40:01 volumio shairport-sync[18824]: free(): double free detected in tcache 2 May 18 17:40:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=6/ABRT May 18 17:40:01 volumio systemd[1]: shairport-sync.service: Failed with result 'signal'. May 18 17:40:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 18 17:40:01 volumio sudo[18823]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: info: Shairport-Sync Started May 18 17:40:01 volumio mpd[18790]: May 18 17:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 18 17:40:01 volumio systemd[1]: Started Music Player Daemon. May 18 17:40:01 volumio sudo[18760]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio sudo[18775]: pam_unix(sudo:session): session closed for user root May 18 17:40:01 volumio volumio[9657]: error: MPD error: The expression evaluated to a falsy value: May 18 17:40:01 volumio volumio[9657]: assert.ok(self.idling) May 18 17:40:01 volumio volumio[9657]: error: The expression evaluated to a falsy value: May 18 17:40:01 volumio volumio[9657]: assert.ok(self.idling) May 18 17:40:01 volumio volumio[9657]: error: updateQueue error: null May 18 17:40:03 volumio volumio[9657]: info: Clearing queue after UPNP request May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::ClearQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::stop May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::updateTrackBlock May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getTrackBlock May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::stPlaybackTimer May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::serviceStop May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::stop May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand stop May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::clearPlayQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::saveQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushQueue May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand stop took 11 milliseconds May 18 17:40:04 volumio volumio[9657]: error: updateQueue error: null May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: error: updateQueue error: null May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:04 volumio volumio[9657]: info: Starting UPNP Playback May 18 17:40:04 volumio volumio[9657]: info: Preparing playback through UPNP May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 4ms May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand status took 4 milliseconds May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand status took 5 milliseconds May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":181,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"NiExshadow - All I Knew","artist":"NiExshadow","album":null,"uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 8ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand status took 3 milliseconds May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":181,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"NiExshadow - All I Knew","artist":"NiExshadow","album":null,"uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 20ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 13 milliseconds May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 13 milliseconds May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":181,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"All I Knew","artist":"NiExshadow","album":"All I Know","uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":181,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"All I Knew","artist":"NiExshadow","album":"All I Know","uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 49ms May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:04 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:04 volumio volumio[9657]: info: May 18 17:40:04 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 46ms May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand status took 45 milliseconds May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 11ms May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand status took 10 milliseconds May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:04 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:04 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":181,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"All I Knew","artist":"NiExshadow","album":"All I Know","uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:04 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:04 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":181,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"All I Knew","artist":"NiExshadow","album":"All I Know","uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:04 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:04 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 83ms May 18 17:40:04 volumio volumio[9657]: info: ------------------------------ 47ms May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:04 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:04 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:04 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 18 17:40:05 volumio volumio[9657]: info: CoreStateMachine::getcurrentVolume May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioRetrievevolume May 18 17:40:05 volumio volumio[9657]: Unable to parse: May 18 17:40:05 volumio volumio[9657]: Simple mixer control 'Master',0 May 18 17:40:05 volumio volumio[9657]: Capabilities: volume cswitch May 18 17:40:05 volumio volumio[9657]: Playback channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Capture channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Limits: -50 - 100 May 18 17:40:05 volumio volumio[9657]: Front Left: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: Front Right: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output May 18 17:40:05 volumio volumio[9657]: Unable to parse: May 18 17:40:05 volumio volumio[9657]: Simple mixer control 'Master',0 May 18 17:40:05 volumio volumio[9657]: Capabilities: volume cswitch May 18 17:40:05 volumio volumio[9657]: Playback channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Capture channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Limits: -50 - 100 May 18 17:40:05 volumio volumio[9657]: Front Left: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: Front Right: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: info: VolumeController:: Volume=undefined Mute =false May 18 17:40:05 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:05 volumio volumio[9657]: info: CoreStateMachine::updateTrackBlock May 18 17:40:05 volumio volumio[9657]: info: CorePlayQueue::getTrackBlock May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioRetrievevolume May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:05 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:05 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:05 volumio volumio[9657]: Unable to parse: May 18 17:40:05 volumio volumio[9657]: Simple mixer control 'Master',0 May 18 17:40:05 volumio volumio[9657]: Capabilities: volume cswitch May 18 17:40:05 volumio volumio[9657]: Playback channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Capture channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Limits: -50 - 100 May 18 17:40:05 volumio volumio[9657]: Front Left: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: Front Right: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output May 18 17:40:05 volumio volumio[9657]: Unable to parse: May 18 17:40:05 volumio volumio[9657]: Simple mixer control 'Master',0 May 18 17:40:05 volumio volumio[9657]: Capabilities: volume cswitch May 18 17:40:05 volumio volumio[9657]: Playback channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Capture channels: Front Left - Front Right May 18 17:40:05 volumio volumio[9657]: Limits: -50 - 100 May 18 17:40:05 volumio volumio[9657]: Front Left: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: Front Right: 0 [17%] [-30.00dB] Capture [off] May 18 17:40:05 volumio volumio[9657]: info: VolumeController:: Volume=undefined Mute =false May 18 17:40:05 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:05 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:05 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:05 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:09 volumio volumio[9657]: info: May 18 17:40:09 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:09 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:09 volumio volumio[9657]: info: May 18 17:40:09 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:09 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:09 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:40:09 volumio volumio[9657]: info: sendMpdCommand status took 0 milliseconds May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:09 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:40:09 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:09 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:09 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:09 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:09 volumio volumio[9657]: 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":"All I Knew","artist":"NiExshadow","album":"All I Know","uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:09 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::syncState stateService stop May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::stPlaybackTimer May 18 17:40:09 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:09 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:09 volumio volumio[9657]: 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":"All I Knew","artist":"NiExshadow","album":"All I Know","uri":"http://fsandroid.kugou.com/202505181740/89ea09ee8c52221c9deee9456c30587d/v3/1a19808588efd69caee19d742201932d/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx722043324_quviper_tape_s1983332859.mp3","trackType":"mp3"} May 18 17:40:09 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::syncState stateService stop May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:09 volumio volumio[9657]: info: No code May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:09 volumio volumio[9657]: info: ------------------------------ 24ms May 18 17:40:09 volumio volumio[9657]: info: ------------------------------ 23ms May 18 17:40:09 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:09 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:09 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:09 volumio volumio[9657]: info: Clearing queue after UPNP request May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::ClearQueue May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::stop May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::clearPlayQueue May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::saveQueue May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushQueue May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: error: updateQueue error: null May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:10 volumio volumio[9657]: error: updateQueue error: null May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:10 volumio volumio[9657]: info: Starting UPNP Playback May 18 17:40:10 volumio volumio[9657]: info: Preparing playback through UPNP May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::setConsumeUpdateService mpd May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 2ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 1ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand status took 2 milliseconds May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand status took 4 milliseconds May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:10 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:10 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dirty Nano、Alina Eremia - Promite-Mi","artist":"Dirty Nano、Alina Eremia","album":null,"uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:10 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 6ms May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:10 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:10 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dirty Nano、Alina Eremia - Promite-Mi","artist":"Dirty Nano、Alina Eremia","album":null,"uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:10 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:10 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:10 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:10 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dirty Nano、Alina Eremia - Promite-Mi","artist":"Dirty Nano、Alina Eremia","album":null,"uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:10 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:10 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:10 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:10 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Dirty Nano、Alina Eremia - Promite-Mi","artist":"Dirty Nano、Alina Eremia","album":null,"uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:10 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:10 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 42ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 40ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 40ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces system playlist update May 18 17:40:10 volumio volumio[9657]: info: Ignoring MPD Status Update May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 7ms May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 6ms May 18 17:40:10 volumio volumio[9657]: info: May 18 17:40:10 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand status took 3 milliseconds May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand status took 3 milliseconds May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:10 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:10 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":230,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Promite-Mi","artist":"Dirty Nano/Alina Eremia","album":"Promite-Mi","uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:10 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:10 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 22ms May 18 17:40:10 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 24 milliseconds May 18 17:40:10 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:10 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:10 volumio volumio[9657]: verbose: In UPNP mode May 18 17:40:10 volumio volumio[9657]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":230,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Promite-Mi","artist":"Dirty Nano/Alina Eremia","album":"Promite-Mi","uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:10 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState stateService play May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:10 volumio volumio[9657]: info: Received an update from plugin. extracting info from payload May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:10 volumio volumio[9657]: info: ------------------------------ 40ms May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:10 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:10 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:10 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:29 volumio volumio[9657]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 18 17:40:29 volumio volumio[9657]: info: Retrying Login Due to Network Error May 18 17:40:33 volumio volumio[9657]: info: May 18 17:40:33 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:33 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:33 volumio volumio[9657]: info: May 18 17:40:33 volumio volumio[9657]: ---------------------------- MPD announces state update: player May 18 17:40:33 volumio volumio[9657]: info: ControllerMpd::getState May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand status May 18 17:40:33 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:40:33 volumio volumio[9657]: info: sendMpdCommand status took 1 milliseconds May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::parseState May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 17:40:33 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 17:40:33 volumio volumio[9657]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:33 volumio volumio[9657]: verbose: ControllerMpd::parseTrackInfo May 18 17:40:33 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:33 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:33 volumio volumio[9657]: 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":"Promite-Mi","artist":"Dirty Nano/Alina Eremia","album":"Promite-Mi","uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:33 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::syncState stateService stop May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus play May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::stPlaybackTimer May 18 17:40:33 volumio volumio[9657]: info: ControllerMpd::pushState May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::servicePushState May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:33 volumio volumio[9657]: info: CorePlayQueue::getTrack 0 May 18 17:40:33 volumio volumio[9657]: 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":"Promite-Mi","artist":"Dirty Nano/Alina Eremia","album":"Promite-Mi","uri":"http://fsandroid.kugou.com/202505181740/b14eb90a5261d9c7de6458cff9588495/v3/deaffe006ca8b754ca4a04ae14dd1c63/yp/full/ap1005_us997964742_df348qg23rd2hi33ugpv3o5d3x_pi2_mx153787633_quviper_tape_s4202271472.mp3","trackType":"mp3"} May 18 17:40:33 volumio volumio[9657]: verbose: CURRENT POSITION 0 May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::syncState stateService stop May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::syncState currentStatus stop May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:33 volumio volumio[9657]: info: No code May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::pushState May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::volumioPushState May 18 17:40:33 volumio volumio[9657]: info: ------------------------------ 25ms May 18 17:40:33 volumio volumio[9657]: info: ------------------------------ 25ms May 18 17:40:33 volumio volumio[9657]: info: CoreCommandRouter::volumioGetQueue May 18 17:40:33 volumio volumio[9657]: info: CoreStateMachine::getQueue May 18 17:40:33 volumio volumio[9657]: info: CorePlayQueue::getQueue May 18 17:40:39 volumio volumio[9657]: info: MyVolumio login type: Token May 18 17:40:50 volumio volumio[9657]: info: CoreCommandRouter::volumioGetState May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:52 volumio volumio[9657]: info: Retrieving Cloud Streaming UI May 18 17:40:52 volumio volumio[9657]: info: Getting Tidal Cloud Configuration May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:52 volumio volumio[9657]: info: Getting Qobuz Cloud Configuration May 18 17:40:52 volumio volumio[9657]: info: Asking plugin for UI Config May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:52 volumio volumio[9657]: info: Getting Spotify Cloud Configuration May 18 17:40:52 volumio volumio[9657]: info: Asking plugin for UI Config May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:52 volumio volumio[9657]: info: Saving Spotify Acccount May 18 17:40:52 volumio volumio[9657]: info: Got Tidal Cloud Configuration May 18 17:40:52 volumio volumio[9657]: info: Got it May 18 17:40:52 volumio volumio[9657]: info: Got it May 18 17:40:52 volumio volumio[9657]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::getUIConfigOnPlugin May 18 17:40:52 volumio volumio[9657]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::volumioGetBrowseSources May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::volumioGetBrowseSources May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::volumioGetBrowseSources May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 18 17:40:52 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 18 17:40:55 volumio volumio[9657]: info: Disabling MyMusic plugin upnp May 18 17:40:55 volumio sudo[19387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service May 18 17:40:55 volumio sudo[19387]: pam_unix(sudo:session): session opened for user root by (uid=0) May 18 17:40:55 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... May 18 17:40:55 volumio volumio[9657]: error: Upnp client error: Error: This socket has been ended by the other party May 18 17:40:56 volumio volumio[9657]: info: Enabling MyMusic plugin upnp May 18 17:40:56 volumio volumio[9657]: info: Enabling plugin upnp May 18 17:40:56 volumio volumio[9657]: info: Loading plugin "upnp"... May 18 17:40:56 volumio volumio[9657]: info: [1747561256379] Starting Upmpd Daemon May 18 17:40:56 volumio volumio[9657]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 18 17:40:56 volumio volumio[9657]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 17:40:56 volumio volumio[9657]: Error: listen EADDRINUSE: address already in use :::6599 May 18 17:40:56 volumio volumio[9657]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) May 18 17:40:56 volumio volumio[9657]: at listenInCluster (net.js:1379:12) May 18 17:40:56 volumio volumio[9657]: at Server.listen (net.js:1465:7) May 18 17:40:56 volumio volumio[9657]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) May 18 17:40:56 volumio volumio[9657]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) May 18 17:40:56 volumio volumio[9657]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) May 18 17:40:56 volumio volumio[9657]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 18 17:40:56 volumio volumio[9657]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { May 18 17:40:56 volumio volumio[9657]: code: 'EADDRINUSE', May 18 17:40:56 volumio volumio[9657]: errno: -98, May 18 17:40:56 volumio volumio[9657]: syscall: 'listen', May 18 17:40:56 volumio volumio[9657]: address: '::', May 18 17:40:56 volumio volumio[9657]: port: 6599 May 18 17:40:56 volumio volumio[9657]: } May 18 17:40:56 volumio volumio[9657]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 17:40:56 volumio sudo[19400]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-18 17:39 May 18 17:40:56 volumio sudo[19400]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 10:07:11 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="dc77d77f02ef88ea816c3d31de871e8f"