-- Logs begin at Thu 2025-09-11 14:36:32 HKT, end at Thu 2025-09-11 14:47:32 HKT. -- Sep 11 14:46:03 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:04 volumio volumio[4271]: info: Clearing queue after UPNP request Sep 11 14:46:04 volumio volumio[4271]: info: Sep 11 14:46:04 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:04 volumio volumio[4271]: info: Sep 11 14:46:04 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:04 volumio volumio[4271]: info: sendMpdCommand status took 8 milliseconds Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:04 volumio volumio[4271]: info: sendMpdCommand status took 4 milliseconds Sep 11 14:46:04 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:04 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:04 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":3199,"samplerate":"11.025 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"若把你","artist":"留小雨","album":"若把你","uri":"http://m801.music.126.net/20250911151039/63fd75924993532c5d61dbea96a16b19/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/35264739712/13b9/36f4/3551/dc2391df64e2aff399d8d459a54b4555.flac?vuutv=MYII0dwwTl+dgVr3R7fDG786u0ahgDnZePYxnf1C94BPzyPFDxI3FJajPvT6SjNqF6DJz4i5XX5zD7mrNMNv5qyUQDQ7wZ7s+SkEhPsaiJ4=","trackType":""} Sep 11 14:46:04 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus stop Sep 11 14:46:04 volumio volumio[4271]: info: ------------------------------ 25ms Sep 11 14:46:04 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:04 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:04 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":3199,"samplerate":"11.025 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"若把你","artist":"留小雨","album":"若把你","uri":"http://m801.music.126.net/20250911151039/63fd75924993532c5d61dbea96a16b19/jdymusic/obj/wo3DlMOGwrbDjj7DisKw/35264739712/13b9/36f4/3551/dc2391df64e2aff399d8d459a54b4555.flac?vuutv=MYII0dwwTl+dgVr3R7fDG786u0ahgDnZePYxnf1C94BPzyPFDxI3FJajPvT6SjNqF6DJz4i5XX5zD7mrNMNv5qyUQDQ7wZ7s+SkEhPsaiJ4=","trackType":""} Sep 11 14:46:04 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:04 volumio volumio[4271]: info: Received an update from plugin. extracting info from payload Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: ------------------------------ 72ms Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::ClearQueue Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::stop Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::stPlaybackTimer Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::updateTrackBlock Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrackBlock Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::serviceStop Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::stop Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand stop Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::clearPlayQueue Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::saveQueue Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushQueue Sep 11 14:46:04 volumio volumio[4271]: info: Sep 11 14:46:04 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:04 volumio volumio[4271]: info: sendMpdCommand stop took 16 milliseconds Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:04 volumio volumio[4271]: info: Sep 11 14:46:04 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:04 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:04 volumio volumio[4271]: info: sendMpdCommand status took 2 milliseconds Sep 11 14:46:04 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:04 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 11 14:46:04 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::syncState stateService stop Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus stop Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: No code Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:04 volumio volumio[4271]: info: ------------------------------ 25ms Sep 11 14:46:04 volumio volumio[4271]: error: updateQueue error: null Sep 11 14:46:04 volumio volumio[4271]: info: ------------------------------ 24ms Sep 11 14:46:04 volumio volumio[4271]: info: Starting UPNP Playback Sep 11 14:46:04 volumio volumio[4271]: info: Preparing playback through UPNP Sep 11 14:46:04 volumio volumio[4271]: info: CoreCommandRouter::volumioGetState Sep 11 14:46:04 volumio volumio[4271]: info: CorePlayQueue::getTrack 0 Sep 11 14:46:04 volumio volumio[4271]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 11 14:46:05 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 11 14:46:05 volumio volumio[4271]: info: Sep 11 14:46:05 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:05 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:05 volumio volumio[4271]: info: ------------------------------ 2ms Sep 11 14:46:05 volumio volumio[4271]: info: Sep 11 14:46:05 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:05 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:05 volumio volumio[4271]: info: ------------------------------ 1ms Sep 11 14:46:05 volumio volumio[4271]: info: Sep 11 14:46:05 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:05 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:05 volumio volumio[4271]: info: ------------------------------ 1ms Sep 11 14:46:05 volumio volumio[4271]: info: Sep 11 14:46:05 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:05 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:05 volumio volumio[4271]: info: ------------------------------ 1ms Sep 11 14:46:05 volumio volumio[4271]: info: Sep 11 14:46:05 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:05 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:05 volumio volumio[4271]: info: ------------------------------ 1ms Sep 11 14:46:05 volumio volumio[4271]: info: Sep 11 14:46:05 volumio volumio[4271]: ---------------------------- MPD announces system playlist update Sep 11 14:46:05 volumio volumio[4271]: info: Ignoring MPD Status Update Sep 11 14:46:05 volumio volumio[4271]: info: ------------------------------ 1ms Sep 11 14:46:06 volumio volumio[4271]: info: Sep 11 14:46:06 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:06 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:06 volumio volumio[4271]: info: sendMpdCommand status took 2 milliseconds Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:06 volumio volumio[4271]: info: Sep 11 14:46:06 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:06 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:06 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:06 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:06 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:06 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":3810,"samplerate":"11.025 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:06 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus stop Sep 11 14:46:06 volumio volumio[4271]: info: ------------------------------ 11ms Sep 11 14:46:06 volumio volumio[4271]: info: sendMpdCommand status took 5 milliseconds Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:06 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 11 14:46:06 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:06 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:06 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:06 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":3810,"samplerate":"11.025 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:06 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:06 volumio volumio[4271]: info: Received an update from plugin. extracting info from payload Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:06 volumio volumio[4271]: info: ------------------------------ 38ms Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:06 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:06 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:06 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:06 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:07 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:09 volumio volumio[4271]: info: Sep 11 14:46:09 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:09 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:09 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:09 volumio volumio[4271]: info: sendMpdCommand status took 1 milliseconds Sep 11 14:46:09 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:09 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:09 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 11 14:46:09 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:09 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:09 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:09 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:09 volumio volumio[4271]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2823,"duration":3810,"samplerate":"11.025 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:09 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:09 volumio volumio[4271]: info: CoreStateMachine::syncState stateService pause Sep 11 14:46:09 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:09 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:09 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:09 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:09 volumio volumio[4271]: info: CoreStateMachine::stPlaybackTimer Sep 11 14:46:09 volumio volumio[4271]: info: ------------------------------ 13ms Sep 11 14:46:09 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:09 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:09 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:15 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:19 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:20 volumio volumio[4271]: info: Sep 11 14:46:20 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:20 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:20 volumio volumio[4271]: info: sendMpdCommand status took 1 milliseconds Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:20 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:20 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:20 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:20 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3551,"duration":3810,"samplerate":"11.025 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"7015 Kbps","isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:20 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:20 volumio volumio[4271]: info: Received an update from plugin. extracting info from payload Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:20 volumio volumio[4271]: info: ------------------------------ 31ms Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: Sep 11 14:46:20 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:20 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:20 volumio volumio[4271]: info: Sep 11 14:46:20 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:20 volumio volumio[4271]: info: sendMpdCommand status took 23 milliseconds Sep 11 14:46:20 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:20 volumio volumio[4271]: info: sendMpdCommand status took 2 milliseconds Sep 11 14:46:20 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:20 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:20 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:20 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2000,"duration":9617,"samplerate":"8 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:20 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:20 volumio volumio[4271]: info: Received an update from plugin. extracting info from payload Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:20 volumio volumio[4271]: info: ------------------------------ 56ms Sep 11 14:46:20 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 28 milliseconds Sep 11 14:46:20 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:20 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:20 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:20 volumio volumio[4271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2000,"duration":9617,"samplerate":"8 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:20 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::syncState stateService play Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:20 volumio volumio[4271]: info: Received an update from plugin. extracting info from payload Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:20 volumio volumio[4271]: info: ------------------------------ 59ms Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:20 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:20 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:23 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:23 volumio volumio[4271]: info: Sep 11 14:46:23 volumio volumio[4271]: ---------------------------- MPD announces state update: player Sep 11 14:46:23 volumio volumio[4271]: info: ControllerMpd::getState Sep 11 14:46:23 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand status Sep 11 14:46:23 volumio volumio[4271]: info: sendMpdCommand status took 0 milliseconds Sep 11 14:46:23 volumio volumio[4271]: verbose: ControllerMpd::parseState Sep 11 14:46:23 volumio volumio[4271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 11 14:46:23 volumio volumio[4271]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 11 14:46:23 volumio volumio[4271]: verbose: ControllerMpd::parseTrackInfo Sep 11 14:46:23 volumio volumio[4271]: info: ControllerMpd::pushState Sep 11 14:46:23 volumio volumio[4271]: info: CoreCommandRouter::servicePushState Sep 11 14:46:23 volumio volumio[4271]: verbose: In UPNP mode Sep 11 14:46:23 volumio volumio[4271]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2886,"duration":9617,"samplerate":"8 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2537 Kbps","isStreaming":false,"title":"枕边童话","artist":"小田音乐社","album":"枕边童话","uri":"http://m7.music.126.net/20250911151104/3ec6f89bd4aaf33f386ac9b63e26d622/ymusic/obj/w5zDlMODwrDDiGjCn8Ky/26319599876/b960/db07/97db/f63f928fe80abeca2631580b4edb7a2c.flac?vuutv=3Bj/MA5fVYoKr1I/qN7snkJxu+zN+U6j6dTIJmflPx2KuECgb2VxtOQDpSQw8VncYFXcHev8Gsi7XKqwZyB3CPb7dqZ3cxvTHMHQrYk6N04=","trackType":""} Sep 11 14:46:23 volumio volumio[4271]: verbose: CURRENT POSITION 0 Sep 11 14:46:23 volumio volumio[4271]: info: CoreStateMachine::syncState stateService pause Sep 11 14:46:23 volumio volumio[4271]: info: CoreStateMachine::syncState currentStatus play Sep 11 14:46:23 volumio volumio[4271]: info: CoreStateMachine::pushState Sep 11 14:46:23 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 11 14:46:23 volumio volumio[4271]: info: CoreCommandRouter::volumioPushState Sep 11 14:46:23 volumio volumio[4271]: info: CoreStateMachine::stPlaybackTimer Sep 11 14:46:23 volumio volumio[4271]: info: ------------------------------ 13ms Sep 11 14:46:23 volumio volumio[4271]: info: CoreCommandRouter::volumioGetQueue Sep 11 14:46:23 volumio volumio[4271]: info: CoreStateMachine::getQueue Sep 11 14:46:23 volumio volumio[4271]: info: CorePlayQueue::getQueue Sep 11 14:46:27 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:31 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:35 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:39 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:43 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:47 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:51 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:55 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:46:59 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:47:03 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 11 14:47:05 volumio ntpd[3466]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 11 14:47:07 volumio volumio[4271]: info: CoreCommandRouter::volumioGetState Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 11 14:47:11 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 11 14:47:29 volumio volumio[4271]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Sep 11 14:47:29 volumio sudo[5320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 11 14:47:29 volumio sudo[5320]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio sudo[5320]: pam_unix(sudo:session): session closed for user root Sep 11 14:47:29 volumio sudo[5322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 11 14:47:29 volumio sudo[5322]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 11 14:47:29 volumio systemd[1]: Stopping Music Player Daemon... Sep 11 14:47:29 volumio systemd[1]: mpd.service: Succeeded. Sep 11 14:47:29 volumio systemd[1]: Stopped Music Player Daemon. Sep 11 14:47:29 volumio volumio[4271]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 14:47:29 volumio volumio[4271]: info: MPD Permissions set Sep 11 14:47:29 volumio systemd[1]: Starting Music Player Daemon... Sep 11 14:47:29 volumio sudo[5332]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 11 14:47:29 volumio sudo[5332]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 14:47:29 volumio sudo[5332]: pam_unix(sudo:session): session closed for user root Sep 11 14:47:30 volumio mpd[5335]: Sep 11 14:47 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 11 14:47:30 volumio systemd[1]: Started Music Player Daemon. Sep 11 14:47:30 volumio sudo[5322]: pam_unix(sudo:session): session closed for user root Sep 11 14:47:30 volumio volumio[4271]: error: updateQueue error: null Sep 11 14:47:32 volumio volumio[4271]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 11 14:47:32 volumio volumio[4271]: Error: connect ETIMEDOUT 111.243.214.169:443 Sep 11 14:47:32 volumio volumio[4271]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Sep 11 14:47:32 volumio volumio[4271]: errno: -110, Sep 11 14:47:32 volumio volumio[4271]: code: 'ETIMEDOUT', Sep 11 14:47:32 volumio volumio[4271]: syscall: 'connect', Sep 11 14:47:32 volumio volumio[4271]: address: '111.243.214.169', Sep 11 14:47:32 volumio volumio[4271]: port: 443 Sep 11 14:47:32 volumio volumio[4271]: } Sep 11 14:47:32 volumio volumio[4271]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 11 14:47:32 volumio sudo[5363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-11 14:46 Sep 11 14:47:32 volumio sudo[5363]: 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="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"