-- Logs begin at Sun 2024-04-28 02:34:15 UTC, end at Mon 2024-04-29 05:25:26 UTC. -- Apr 29 05:24:09 volumio volumio[8426]: info: Clearing queue after UPNP request Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::ClearQueue Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::stop Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:24:09 volumio volumio[8426]: verbose: UNSET VOLATILE Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::updateTrackBlock Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrackBlock Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::serviceStop Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: info: ControllerMpd::stop Apr 29 05:24:09 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::clearPlayQueue Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::saveQueue Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:24:09 volumio volumio[8426]: info: sendMpdCommand stop took 70 milliseconds Apr 29 05:24:09 volumio volumio[8426]: info: Apr 29 05:24:09 volumio volumio[8426]: ---------------------------- MPD announces state update: player Apr 29 05:24:09 volumio volumio[8426]: info: ControllerMpd::getState Apr 29 05:24:09 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:09 volumio volumio[8426]: info: Apr 29 05:24:09 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:09 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:09 volumio volumio[8426]: info: sendMpdCommand status took 3 milliseconds Apr 29 05:24:09 volumio volumio[8426]: verbose: ControllerMpd::parseState Apr 29 05:24:09 volumio volumio[8426]: info: ControllerMpd::pushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::servicePushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: 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} Apr 29 05:24:09 volumio volumio[8426]: verbose: CURRENT POSITION 0 Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::syncState stateService stop Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:09 volumio volumio[8426]: info: No code Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:09 volumio volumio[8426]: info: ------------------------------ 25ms Apr 29 05:24:09 volumio volumio[8426]: info: Starting UPNP Playback Apr 29 05:24:09 volumio volumio[8426]: info: Preparing playback through UPNP Apr 29 05:24:09 volumio volumio[8426]: info: CoreCommandRouter::volumioGetState Apr 29 05:24:09 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:09 volumio volumio[8426]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:24:09 volumio volumio[8426]: error: updateQueue error: null Apr 29 05:24:09 volumio volumio[8426]: info: ------------------------------ 26ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 2ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 3ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 2ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 3ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 2ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 3ms Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces state update: player Apr 29 05:24:10 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:24:10 volumio volumio[8426]: info: ControllerMpd::getState Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:10 volumio volumio[8426]: info: sendMpdCommand status took 13 milliseconds Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::parseState Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:10 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:10 volumio volumio[8426]: info: Apr 29 05:24:10 volumio volumio[8426]: ---------------------------- MPD announces state update: player Apr 29 05:24:10 volumio volumio[8426]: info: ControllerMpd::getState Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:10 volumio volumio[8426]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:24:10 volumio volumio[8426]: info: ControllerMpd::pushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::servicePushState Apr 29 05:24:10 volumio volumio[8426]: verbose: In UPNP mode Apr 29 05:24:10 volumio volumio[8426]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"殇【大提琴版】","artist":"吴登凯YoYoCello","album":null,"uri":"http://isure6.stream.qqmusic.qq.com/M50000411pjy2m118A.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=512B373656DB02A1581F990C00D0E2AC3F5EFCDA1521FAF1163BBFA675746608FEC969CCD4A1FB7923836B45DA6521BF08FAE881DB98F55E&uin=1152921504689611133&src=M50000336nnG48lbg2.mp3&redirect=1&fromtag=101042","trackType":""} Apr 29 05:24:10 volumio volumio[8426]: verbose: CURRENT POSITION 0 Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::syncState stateService play Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 34ms Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 18ms Apr 29 05:24:10 volumio volumio[8426]: info: sendMpdCommand status took 17 milliseconds Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::parseState Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::getQueue Apr 29 05:24:10 volumio volumio[8426]: info: CorePlayQueue::getQueue Apr 29 05:24:10 volumio volumio[8426]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 29 05:24:10 volumio volumio[8426]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:24:10 volumio volumio[8426]: info: ControllerMpd::pushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::servicePushState Apr 29 05:24:10 volumio volumio[8426]: verbose: In UPNP mode Apr 29 05:24:10 volumio volumio[8426]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"殇【大提琴版】","artist":"吴登凯YoYoCello","album":null,"uri":"http://isure6.stream.qqmusic.qq.com/M50000411pjy2m118A.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=512B373656DB02A1581F990C00D0E2AC3F5EFCDA1521FAF1163BBFA675746608FEC969CCD4A1FB7923836B45DA6521BF08FAE881DB98F55E&uin=1152921504689611133&src=M50000336nnG48lbg2.mp3&redirect=1&fromtag=101042","trackType":""} Apr 29 05:24:10 volumio volumio[8426]: verbose: CURRENT POSITION 0 Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::syncState stateService play Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:24:10 volumio volumio[8426]: info: Received an update from plugin. extracting info from payload Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:10 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:10 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:10 volumio volumio[8426]: info: ------------------------------ 45ms Apr 29 05:24:12 volumio volumio[8426]: info: Clearing queue after UPNP request Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::ClearQueue Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::stop Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:24:12 volumio volumio[8426]: verbose: UNSET VOLATILE Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::updateTrackBlock Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::getTrackBlock Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::serviceStop Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:12 volumio volumio[8426]: info: ControllerMpd::stop Apr 29 05:24:12 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::clearPlayQueue Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::saveQueue Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:24:12 volumio volumio[8426]: info: Apr 29 05:24:12 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:12 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:12 volumio volumio[8426]: info: Apr 29 05:24:12 volumio volumio[8426]: ---------------------------- MPD announces state update: player Apr 29 05:24:12 volumio volumio[8426]: info: ControllerMpd::getState Apr 29 05:24:12 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:12 volumio volumio[8426]: info: sendMpdCommand stop took 93 milliseconds Apr 29 05:24:12 volumio volumio[8426]: info: Starting UPNP Playback Apr 29 05:24:12 volumio volumio[8426]: info: Preparing playback through UPNP Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioGetState Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:24:12 volumio volumio[8426]: error: updateQueue error: null Apr 29 05:24:12 volumio volumio[8426]: info: ------------------------------ 7ms Apr 29 05:24:12 volumio volumio[8426]: info: sendMpdCommand status took 5 milliseconds Apr 29 05:24:12 volumio volumio[8426]: verbose: ControllerMpd::parseState Apr 29 05:24:12 volumio volumio[8426]: info: ControllerMpd::pushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::servicePushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:12 volumio volumio[8426]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:12 volumio volumio[8426]: 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} Apr 29 05:24:12 volumio volumio[8426]: verbose: CURRENT POSITION 0 Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::syncState stateService stop Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:12 volumio volumio[8426]: info: No code Apr 29 05:24:12 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:12 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:12 volumio volumio[8426]: info: ------------------------------ 25ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 3ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 3ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 2ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 2ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 2ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 3ms Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces state update: player Apr 29 05:24:13 volumio volumio[8426]: info: ControllerMpd::getState Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:13 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:24:13 volumio volumio[8426]: info: sendMpdCommand status took 13 milliseconds Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::parseState Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces system playlist update Apr 29 05:24:13 volumio volumio[8426]: info: Ignoring MPD Status Update Apr 29 05:24:13 volumio volumio[8426]: info: Apr 29 05:24:13 volumio volumio[8426]: ---------------------------- MPD announces state update: player Apr 29 05:24:13 volumio volumio[8426]: info: ControllerMpd::getState Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:13 volumio volumio[8426]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:24:13 volumio volumio[8426]: info: ControllerMpd::pushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::servicePushState Apr 29 05:24:13 volumio volumio[8426]: verbose: In UPNP mode Apr 29 05:24:13 volumio volumio[8426]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":147,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Lead, Kindly Light","artist":"Steven Sharp Nelson","album":"Grace: A Sacred Cello Collection","uri":"http://isure6.stream.qqmusic.qq.com/M500003SAjeU1aJGc8.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=138DAC0C219F23874F304150A1F471E81FD59D4A083D9517F4E51517C5DA7984EBC21A40DC852B953C189256F3A0F897C8222D01884BC1F9&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:24:13 volumio volumio[8426]: verbose: CURRENT POSITION 0 Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::syncState stateService play Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 33ms Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 25ms Apr 29 05:24:13 volumio volumio[8426]: info: sendMpdCommand status took 24 milliseconds Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::parseState Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:24:13 volumio volumio[8426]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 29 05:24:13 volumio volumio[8426]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:24:13 volumio volumio[8426]: info: ControllerMpd::pushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::servicePushState Apr 29 05:24:13 volumio volumio[8426]: verbose: In UPNP mode Apr 29 05:24:13 volumio volumio[8426]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":147,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Lead, Kindly Light","artist":"Steven Sharp Nelson","album":"Grace: A Sacred Cello Collection","uri":"http://isure6.stream.qqmusic.qq.com/M500003SAjeU1aJGc8.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=138DAC0C219F23874F304150A1F471E81FD59D4A083D9517F4E51517C5DA7984EBC21A40DC852B953C189256F3A0F897C8222D01884BC1F9&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:24:13 volumio volumio[8426]: verbose: CURRENT POSITION 0 Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::syncState stateService play Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:24:13 volumio volumio[8426]: info: Received an update from plugin. extracting info from payload Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::pushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:13 volumio volumio[8426]: info: ------------------------------ 56ms Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::getQueue Apr 29 05:24:13 volumio volumio[8426]: info: CorePlayQueue::getQueue Apr 29 05:24:13 volumio volumio[8426]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:24:13 volumio volumio[8426]: info: CoreStateMachine::getQueue Apr 29 05:24:13 volumio volumio[8426]: info: CorePlayQueue::getQueue Apr 29 05:24:13 volumio volumio[8426]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 29 05:24:13 volumio volumio[8426]: { Error: connect ETIMEDOUT 103.97.3.19:443 Apr 29 05:24:13 volumio volumio[8426]: at Object._errnoException (util.js:1022:11) Apr 29 05:24:13 volumio volumio[8426]: at _exceptionWithHostPort (util.js:1044:20) Apr 29 05:24:13 volumio volumio[8426]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Apr 29 05:24:13 volumio volumio[8426]: code: 'ETIMEDOUT', Apr 29 05:24:13 volumio volumio[8426]: errno: 'ETIMEDOUT', Apr 29 05:24:13 volumio volumio[8426]: syscall: 'connect', Apr 29 05:24:13 volumio volumio[8426]: address: '103.97.3.19', Apr 29 05:24:13 volumio volumio[8426]: port: 443 } Apr 29 05:24:13 volumio volumio[8426]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 29 05:24:15 volumio sudo[8956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-29 05:23 Apr 29 05:24:15 volumio sudo[8956]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:15 volumio kernel: Under-voltage detected! (0x00050005) Apr 29 05:24:15 volumio sudo[8956]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:17 volumio volumio-remote-updater[607]: [2024-04-29 05:24:17] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Apr 29 05:24:17 volumio volumio-remote-updater[607]: [2024-04-29 05:24:17] [error] handle_read_frame error: websocketpp.transport:2 (Underlying Transport Error) Apr 29 05:24:17 volumio volumio-remote-updater[607]: [2024-04-29 05:24:17] [disconnect] Disconnect close local:[1006,Underlying Transport Error] remote:[1006] Apr 29 05:24:17 volumio systemd[1]: volumio.service: main process exited, code=exited, status=1/FAILURE Apr 29 05:24:17 volumio systemd[1]: Unit volumio.service entered failed state. Apr 29 05:24:17 volumio systemd[1]: Starting dynamicswap service... Apr 29 05:24:17 volumio systemd[1]: Started dynamicswap service. Apr 29 05:24:17 volumio systemd[1]: volumio.service holdoff time over, scheduling restart. Apr 29 05:24:17 volumio systemd[1]: Starting dynamicswap service... Apr 29 05:24:17 volumio systemd[1]: Started dynamicswap service. Apr 29 05:24:17 volumio systemd[1]: Stopping Volumio Backend Module... Apr 29 05:24:17 volumio systemd[1]: Starting Volumio Backend Module... Apr 29 05:24:17 volumio systemd[1]: Started Volumio Backend Module. Apr 29 05:24:18 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:18 volumio volumio[8980]: info: ----- Volumio2 ---- Apr 29 05:24:18 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:18 volumio volumio[8980]: info: ----- System startup ---- Apr 29 05:24:18 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:19 volumio volumio[8980]: info: MYVOLUMIO Environment detected Apr 29 05:24:19 volumio volumio[8980]: info: Plugin folders cleanup Apr 29 05:24:19 volumio volumio[8980]: info: Scanning into folder /volumio/app/plugins/ Apr 29 05:24:19 volumio volumio[8980]: info: Scanning category audio_interface Apr 29 05:24:19 volumio volumio[8980]: info: Scanning category miscellanea Apr 29 05:24:19 volumio volumio[8980]: info: Scanning category music_service Apr 29 05:24:19 volumio volumio[8980]: info: Scanning category plugins.json Apr 29 05:24:19 volumio volumio[8980]: info: Scanning category system_controller Apr 29 05:24:19 volumio volumio[8980]: info: Scanning category user_interface Apr 29 05:24:19 volumio volumio[8980]: info: Scanning into folder /data/plugins/ Apr 29 05:24:19 volumio volumio[8980]: info: Plugin folders cleanup completed Apr 29 05:24:19 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:19 volumio volumio[8980]: info: ----- Core plugins startup ---- Apr 29 05:24:19 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:19 volumio volumio[8980]: info: Loading plugins from folder /volumio/app/plugins/ Apr 29 05:24:19 volumio volumio[8980]: info: Adding plugin upnp to MyMusic Plugins Apr 29 05:24:19 volumio volumio[8980]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 29 05:24:19 volumio volumio[8980]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 29 05:24:19 volumio volumio[8980]: info: Loading plugins from folder /data/plugins/ Apr 29 05:24:19 volumio volumio[8980]: info: Loading plugin "system"... Apr 29 05:24:19 volumio volumio[8980]: info: Loading plugin "appearance"... Apr 29 05:24:22 volumio volumio-remote-updater[607]: [2024-04-29 05:24:22] [connect] Successful connection Apr 29 05:24:22 volumio volumio[8980]: info: Loading plugin "network"... Apr 29 05:24:22 volumio volumio[8980]: info: Refreshing Cached IP Addresses Apr 29 05:24:22 volumio sudo[9007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 29 05:24:22 volumio volumio[8980]: info: Loading plugin "services"... Apr 29 05:24:22 volumio sudo[9007]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:22 volumio volumio[8980]: info: Loading plugin "alsa_controller"... Apr 29 05:24:22 volumio sudo[9007]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:22 volumio sudo[9011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 29 05:24:22 volumio sudo[9011]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:22 volumio sudo[9011]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:22 volumio volumio[8980]: info: Loading plugin "wizard"... Apr 29 05:24:22 volumio volumio[8980]: info: Loading plugin "volumio_command_line_client"... Apr 29 05:24:23 volumio volumio[8980]: info: Loading plugin "upnp"... Apr 29 05:24:23 volumio volumio[8980]: info: [1714368263022] Starting Upmpd Daemon Apr 29 05:24:23 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 29 05:24:23 volumio volumio[8980]: info: Loading plugin "my_music"... Apr 29 05:24:23 volumio volumio[8980]: info: Loading plugin "mpd"... Apr 29 05:24:23 volumio volumio[8980]: info: Loading plugin "upnp_browser"... Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "networkfs"... Apr 29 05:24:24 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "alarm-clock"... Apr 29 05:24:24 volumio sudo[9033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //X201-PC/TDDOWNLOAD /mnt/NAS/TDDOWNLOAD Apr 29 05:24:24 volumio sudo[9033]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "airplay_emulation"... Apr 29 05:24:24 volumio kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 29 05:24:24 volumio volumio[8980]: info: Starting Shairport Sync Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "last_100"... Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "webradio"... Apr 29 05:24:24 volumio sudo[9033]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:24 volumio kernel: Status code returned 0xc0000022 STATUS_ACCESS_DENIED Apr 29 05:24:24 volumio kernel: CIFS VFS: Send error in SessSetup = -13 Apr 29 05:24:24 volumio kernel: CIFS VFS: cifs_mount failed w/return code = -13 Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "i2s_dacs"... Apr 29 05:24:24 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "volumiodiscovery"... Apr 29 05:24:24 volumio volumio[8980]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 29 05:24:24 volumio node[8980]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 29 05:24:24 volumio node[8980]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 05:24:24 volumio node[8980]: *** WARNING *** For more information see Apr 29 05:24:24 volumio node[8980]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 29 05:24:24 volumio node[8980]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 05:24:24 volumio node[8980]: *** WARNING *** For more information see Apr 29 05:24:24 volumio volumio[8980]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 05:24:24 volumio volumio[8980]: *** WARNING *** For more information see Apr 29 05:24:24 volumio volumio[8980]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 29 05:24:24 volumio volumio[8980]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 05:24:24 volumio volumio[8980]: *** WARNING *** For more information see Apr 29 05:24:24 volumio volumio[8980]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 29 05:24:24 volumio volumio[8980]: Discovery: StartAdv! undefined Apr 29 05:24:24 volumio volumio[8980]: Discovery: Started advertising... Volumio - undefined Apr 29 05:24:24 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "outputs"... Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "albumart"... Apr 29 05:24:24 volumio volumio[8980]: info: Plugin example_plugin is not enabled Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "inputs"... Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "updater_comm"... Apr 29 05:24:24 volumio volumio[8980]: info: Plugin mpdemulation is not enabled Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "rest_api"... Apr 29 05:24:24 volumio volumio[8980]: info: Loading plugin "websocket"... Apr 29 05:24:24 volumio volumio[8980]: info: ___________ START PLUGINS ___________ Apr 29 05:24:24 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 05:24:24 volumio volumio[8980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 05:24:24 volumio volumio[8980]: info: [1714368264941] CoreMusicLibrary::Adding element Media Servers Apr 29 05:24:24 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 05:24:25 volumio volumio[8980]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 29 05:24:25 volumio volumio[8980]: Forking 3 albumart workers Apr 29 05:24:25 volumio volumio[8980]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 05:24:25 volumio volumio[8980]: info: [1714368265063] CoreMusicLibrary::Adding element Last_100 Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 05:24:25 volumio volumio[8980]: info: [1714368265067] CoreMusicLibrary::Adding element Webradio Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 05:24:25 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:25 volumio volumio[8980]: info: ----- MyVolumio plugins startup ---- Apr 29 05:24:25 volumio volumio[8980]: info: ------------------------------------------- Apr 29 05:24:25 volumio volumio[8980]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 29 05:24:25 volumio volumio[8980]: info: Loading i18n strings for locale zh Apr 29 05:24:25 volumio volumio[8980]: Updating browse sources language Apr 29 05:24:25 volumio volumio[8980]: Cannot find translation for sourceMedia Servers Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::initPlayerControls Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: info: BOOT COMPLETED Apr 29 05:24:25 volumio volumio[8980]: [Metrics] CommandRouter: 6s 380.87ms Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 05:24:25 volumio volumio[8980]: aplay: main:722: audio open error: Device or resource busy Apr 29 05:24:25 volumio volumio[8980]: Cannot play startup sound Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::Close All Modals sent Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::Close All Modals sent Apr 29 05:24:25 volumio volumio[8980]: Express server listening on port 3000 Apr 29 05:24:25 volumio volumio[8980]: [Metrics] WebUI: 6s 923.45ms Apr 29 05:24:25 volumio volumio[8980]: Volumio Calling Home Apr 29 05:24:25 volumio volumio[8980]: info: CoreStateMachine::resetVolumioState Apr 29 05:24:25 volumio volumio[8980]: info: CoreStateMachine::getcurrentVolume Apr 29 05:24:25 volumio volumio[8980]: info: CoreCommandRouter::volumioRetrievevolume Apr 29 05:24:26 volumio volumio[8980]: info: Setting Device type: Raspberry PI Apr 29 05:24:26 volumio volumio[8980]: info: Cannot mount NAS TDDOWNLOAD at system boot, trial number 1 ,retrying in 5 seconds Apr 29 05:24:26 volumio volumio[8980]: info: MPD running with PID2373 Apr 29 05:24:26 volumio volumio[8980]: ,establishing connection Apr 29 05:24:26 volumio volumio-remote-updater[607]: [2024-04-29 05:24:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1714368262 101 Apr 29 05:24:26 volumio volumio[8980]: info: Volumio called home Apr 29 05:24:26 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 29 05:24:26 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 29 05:24:26 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 29 05:24:26 volumio volumio[8980]: Starting albumart workers Apr 29 05:24:26 volumio volumio[8980]: info: VolumeController:: Volume=100 Mute =false Apr 29 05:24:26 volumio volumio[8980]: Starting albumart workers Apr 29 05:24:26 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:26 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:26 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:26 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:26 volumio volumio[8980]: info: CoreStateMachine::updateTrackBlock Apr 29 05:24:26 volumio volumio[8980]: info: CorePlayQueue::getTrackBlock Apr 29 05:24:26 volumio volumio[8980]: info: CoreCommandRouter::volumioRetrievevolume Apr 29 05:24:26 volumio volumio[8980]: info: Reloading queue from file Apr 29 05:24:26 volumio volumio[8980]: Starting albumart workers Apr 29 05:24:27 volumio volumio[8980]: info: CoreStateMachine::setRepeat null single undefined Apr 29 05:24:27 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:27 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:27 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:27 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:27 volumio volumio[8980]: info: CoreStateMachine::setRandom null Apr 29 05:24:27 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:27 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:27 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:27 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:27 volumio volumio[8980]: info: Starting Shairport Sync Apr 29 05:24:27 volumio volumio[8980]: info: Starting Shairport Sync Apr 29 05:24:28 volumio sudo[9116]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 29 05:24:28 volumio sudo[9116]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:28 volumio sudo[9119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 29 05:24:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 29 05:24:28 volumio sudo[9119]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:28 volumio systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Apr 29 05:24:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 29 05:24:28 volumio sudo[9116]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:28 volumio volumio[8980]: info: VolumeController:: Volume=100 Mute =false Apr 29 05:24:28 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:28 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:28 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:28 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 29 05:24:28 volumio systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Apr 29 05:24:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 29 05:24:28 volumio sudo[9119]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:28 volumio volumio[8980]: Discovery: adding 82f534ed-d274-4b70-bd12-7733b3956d07 Apr 29 05:24:28 volumio volumio[8980]: info: mDNS: Found device Volumio Apr 29 05:24:28 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:24:28 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:28 volumio volumio[8980]: info: Shairport-Sync Started Apr 29 05:24:28 volumio volumio[8980]: Error adding Membership: Error: addMembership EINVAL Apr 29 05:24:28 volumio volumio[8980]: info: Shairport-Sync Started Apr 29 05:24:28 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:24:28 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:29 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 05:24:29 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 05:24:31 volumio sudo[9153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //X201-PC/TDDOWNLOAD /mnt/NAS/TDDOWNLOAD Apr 29 05:24:31 volumio sudo[9153]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:31 volumio kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 29 05:24:31 volumio kernel: Status code returned 0xc0000022 STATUS_ACCESS_DENIED Apr 29 05:24:31 volumio kernel: CIFS VFS: Send error in SessSetup = -13 Apr 29 05:24:31 volumio kernel: CIFS VFS: cifs_mount failed w/return code = -13 Apr 29 05:24:31 volumio sudo[9153]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:31 volumio volumio[8980]: info: Cannot mount NAS TDDOWNLOAD at system boot, trial number 2 ,retrying in 5 seconds Apr 29 05:24:33 volumio sudo[9169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 29 05:24:33 volumio sudo[9169]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:33 volumio sudo[9169]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:33 volumio sudo[9172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 29 05:24:33 volumio sudo[9172]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:33 volumio sudo[9172]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:33 volumio sudo[9183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 29 05:24:33 volumio sudo[9183]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:33 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 29 05:24:33 volumio sudo[9183]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:33 volumio volumio[8980]: info: Upmpdcli Daemon Started Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 29 05:24:35 volumio volumio[8980]: info: Adding plugin bluetooth to MyMusic Plugins Apr 29 05:24:35 volumio volumio[8980]: info: Adding plugin cd_controller to MyMusic Plugins Apr 29 05:24:35 volumio volumio[8980]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 29 05:24:35 volumio volumio[8980]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 29 05:24:35 volumio volumio[8980]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 29 05:24:36 volumio volumio[8980]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 29 05:24:36 volumio volumio[8980]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 29 05:24:36 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 05:24:36 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 05:24:36 volumio volumio[8980]: info: Starting MyVolumio Remote Streaming Endpoints Apr 29 05:24:36 volumio volumio[8980]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 29 05:24:36 volumio volumio[8980]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 29 05:24:36 volumio volumio[8980]: info: Streaming services startup Apr 29 05:24:36 volumio volumio[8980]: info: Starting Streaming Daemon Apr 29 05:24:36 volumio sudo[9200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 29 05:24:36 volumio sudo[9200]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:36 volumio systemd[1]: Stopping Volumio Streaming Daemon... Apr 29 05:24:36 volumio systemd[1]: Starting Volumio Streaming Daemon... Apr 29 05:24:36 volumio volumio[8980]: info: MyVolumio not started Apr 29 05:24:36 volumio systemd[1]: Started Volumio Streaming Daemon. Apr 29 05:24:36 volumio volumio[8980]: info: Initializing device activation check Apr 29 05:24:36 volumio sudo[9200]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:36 volumio volumio[8980]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 29 05:24:36 volumio volumio-streaming-daemon[9210]: ############################ Apr 29 05:24:36 volumio volumio-streaming-daemon[9210]: # Volumio Streaming Daemon # Apr 29 05:24:36 volumio volumio-streaming-daemon[9210]: # Running on port 7777 # Apr 29 05:24:36 volumio volumio-streaming-daemon[9210]: ############################ Apr 29 05:24:36 volumio volumio-streaming-daemon[9210]: Environment: production Apr 29 05:24:36 volumio sudo[9222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //X201-PC/TDDOWNLOAD /mnt/NAS/TDDOWNLOAD Apr 29 05:24:36 volumio sudo[9222]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:36 volumio kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 29 05:24:36 volumio sudo[9222]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:36 volumio kernel: Status code returned 0xc0000022 STATUS_ACCESS_DENIED Apr 29 05:24:36 volumio kernel: CIFS VFS: Send error in SessSetup = -13 Apr 29 05:24:36 volumio kernel: CIFS VFS: cifs_mount failed w/return code = -13 Apr 29 05:24:36 volumio volumio[8980]: info: Cannot mount NAS TDDOWNLOAD at system boot, trial number 3 ,retrying in 5 seconds Apr 29 05:24:38 volumio volumio-streaming-daemon[9210]: Environment: production Apr 29 05:24:38 volumio volumio[8980]: info: Fetching Streaming Services browse cache Apr 29 05:24:41 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:24:41 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:41 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 29 05:24:41 volumio volumio[8980]: info: CoreCommandRouter::volumioGetVisibleSources Apr 29 05:24:41 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 05:24:41 volumio volumio[8980]: info: Listing playlists Apr 29 05:24:41 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:24:41 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:24:41 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:24:41 volumio sudo[9264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //X201-PC/TDDOWNLOAD /mnt/NAS/TDDOWNLOAD Apr 29 05:24:41 volumio sudo[9264]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:41 volumio kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 29 05:24:41 volumio sudo[9264]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:41 volumio kernel: Status code returned 0xc0000022 STATUS_ACCESS_DENIED Apr 29 05:24:41 volumio kernel: CIFS VFS: Send error in SessSetup = -13 Apr 29 05:24:41 volumio kernel: CIFS VFS: cifs_mount failed w/return code = -13 Apr 29 05:24:41 volumio volumio[8980]: info: Cannot mount NAS TDDOWNLOAD at system boot, trial number 4 ,retrying in 5 seconds Apr 29 05:24:46 volumio sudo[9286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //X201-PC/TDDOWNLOAD /mnt/NAS/TDDOWNLOAD Apr 29 05:24:46 volumio sudo[9286]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 05:24:46 volumio kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 29 05:24:46 volumio sudo[9286]: pam_unix(sudo:session): session closed for user root Apr 29 05:24:46 volumio kernel: Status code returned 0xc0000022 STATUS_ACCESS_DENIED Apr 29 05:24:46 volumio kernel: CIFS VFS: Send error in SessSetup = -13 Apr 29 05:24:46 volumio kernel: CIFS VFS: cifs_mount failed w/return code = -13 Apr 29 05:24:46 volumio volumio[8980]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Apr 29 05:24:51 volumio volumio[8980]: info: Clearing queue after UPNP request Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::ClearQueue Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::stop Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:24:51 volumio volumio[8980]: verbose: UNSET VOLATILE Apr 29 05:24:51 volumio volumio[8980]: info: CorePlayQueue::clearPlayQueue Apr 29 05:24:51 volumio volumio[8980]: info: CorePlayQueue::saveQueue Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:24:51 volumio volumio[8980]: info: Apr 29 05:24:51 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:51 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:51 volumio volumio[8980]: info: Apr 29 05:24:51 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:24:51 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:24:51 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:51 volumio volumio[8980]: info: Starting UPNP Playback Apr 29 05:24:51 volumio volumio[8980]: info: Preparing playback through UPNP Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:24:51 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:24:51 volumio volumio[8980]: error: updateQueue error: null Apr 29 05:24:51 volumio volumio[8980]: info: ------------------------------ 13ms Apr 29 05:24:51 volumio volumio[8980]: info: sendMpdCommand status took 10 milliseconds Apr 29 05:24:51 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:24:51 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:51 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:24:51 volumio volumio[8980]: 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} Apr 29 05:24:51 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::syncState stateService stop Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:51 volumio volumio[8980]: info: No code Apr 29 05:24:51 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:51 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:51 volumio volumio[8980]: info: ------------------------------ 37ms Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 4ms Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:24:52 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:52 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:24:52 volumio volumio[8980]: info: sendMpdCommand status took 12 milliseconds Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:24:52 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:24:52 volumio volumio[8980]: info: Apr 29 05:24:52 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:24:52 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:24:52 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:24:52 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:24:52 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:24:52 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"「千と千尋の神隠し」~いつも何度でも","artist":"久木田薫","album":"GHIBLI the Classics","uri":"http://isure6.stream.qqmusic.qq.com/M500003t3LsR04jNft.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=381036FED7F420CEE38EE06AB68C38D9896E82981A16C51D75847A6488E76C1766CDC5071DD04461010527DBA8BBB5C0EC7CF472E098F439&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:24:52 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 36ms Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 20ms Apr 29 05:24:52 volumio volumio[8980]: info: sendMpdCommand status took 18 milliseconds Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:24:52 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 29 05:24:52 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:24:52 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:24:52 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:24:52 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"「千と千尋の神隠し」~いつも何度でも","artist":"久木田薫","album":"GHIBLI the Classics","uri":"http://isure6.stream.qqmusic.qq.com/M500003t3LsR04jNft.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=381036FED7F420CEE38EE06AB68C38D9896E82981A16C51D75847A6488E76C1766CDC5071DD04461010527DBA8BBB5C0EC7CF472E098F439&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:24:52 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:24:52 volumio volumio[8980]: info: Received an update from plugin. extracting info from payload Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:24:52 volumio volumio[8980]: info: ------------------------------ 49ms Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:24:52 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:24:52 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:24:52 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:24:52 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:24:55 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 05:24:55 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 05:25:00 volumio volumio[8980]: info: Clearing queue after UPNP request Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::ClearQueue Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::stop Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:25:00 volumio volumio[8980]: verbose: UNSET VOLATILE Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::updateTrackBlock Apr 29 05:25:00 volumio volumio[8980]: info: CorePlayQueue::getTrackBlock Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:00 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:00 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:00 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:00 volumio volumio[8980]: info: CoreStateMachine::serviceStop Apr 29 05:25:00 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:00 volumio volumio[8980]: info: ControllerMpd::stop Apr 29 05:25:00 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:25:00 volumio volumio[8980]: info: CorePlayQueue::clearPlayQueue Apr 29 05:25:00 volumio volumio[8980]: info: CorePlayQueue::saveQueue Apr 29 05:25:00 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:00 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:00 volumio volumio[8980]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:01 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:01 volumio volumio[8980]: info: sendMpdCommand stop took 105 milliseconds Apr 29 05:25:01 volumio volumio[8980]: info: Starting UPNP Playback Apr 29 05:25:01 volumio volumio[8980]: info: Preparing playback through UPNP Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:25:01 volumio volumio[8980]: error: updateQueue error: null Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 6ms Apr 29 05:25:01 volumio volumio[8980]: info: sendMpdCommand status took 5 milliseconds Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:01 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:01 volumio volumio[8980]: 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} Apr 29 05:25:01 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::syncState stateService stop Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:01 volumio volumio[8980]: info: No code Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 26ms Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:01 volumio volumio[8980]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E4%B9%85%E6%9C%A8%E7%94%B0%E8%96%AB/GHIBLI%20the%20Classics/434a5242-f79c-4ed2-8a7b-4f8800557b31.jpg' Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:01 volumio volumio[8980]: info: Clearing queue after UPNP request Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:01 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:01 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:25:01 volumio volumio[8980]: info: sendMpdCommand status took 13 milliseconds Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:01 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:01 volumio volumio[8980]: info: Apr 29 05:25:01 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:01 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:01 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:01 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:01 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:01 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"饮酒歌","artist":"Luciano Pavarotti","album":"Ten Top of Opera Hits","uri":"http://isure6.stream.qqmusic.qq.com/M500003sWCob3CGUls.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=5F354A73381C56A7C1665262532EA0CE830F84BF82DF96C5AF78A07398DEB50D4E6C6054D30FB303DC87F29D58DA9E4D37CE366155A5F149&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:01 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 34ms Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 19ms Apr 29 05:25:01 volumio volumio[8980]: info: sendMpdCommand status took 18 milliseconds Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 29 05:25:01 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:01 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:01 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:01 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"饮酒歌","artist":"Luciano Pavarotti","album":"Ten Top of Opera Hits","uri":"http://isure6.stream.qqmusic.qq.com/M500003sWCob3CGUls.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=5F354A73381C56A7C1665262532EA0CE830F84BF82DF96C5AF78A07398DEB50D4E6C6054D30FB303DC87F29D58DA9E4D37CE366155A5F149&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:01 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:25:01 volumio volumio[8980]: info: Received an update from plugin. extracting info from payload Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:01 volumio volumio[8980]: info: ------------------------------ 46ms Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:01 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:01 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::ClearQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::stop Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:25:02 volumio volumio[8980]: verbose: UNSET VOLATILE Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::updateTrackBlock Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getTrackBlock Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::serviceStop Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::stop Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::clearPlayQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::saveQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:02 volumio volumio[8980]: info: sendMpdCommand stop took 92 milliseconds Apr 29 05:25:02 volumio volumio[8980]: info: Starting UPNP Playback Apr 29 05:25:02 volumio volumio[8980]: info: Preparing playback through UPNP Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:25:02 volumio volumio[8980]: error: updateQueue error: null Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 6ms Apr 29 05:25:02 volumio volumio[8980]: info: sendMpdCommand status took 5 milliseconds Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:02 volumio volumio[8980]: 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} Apr 29 05:25:02 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::syncState stateService stop Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: No code Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 26ms Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 4ms Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 4ms Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:02 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:25:02 volumio volumio[8980]: info: sendMpdCommand status took 13 milliseconds Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:02 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:02 volumio volumio[8980]: info: Apr 29 05:25:02 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:02 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:02 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:02 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"「千と千尋の神隠し」~いつも何度でも","artist":"久木田薫","album":"GHIBLI the Classics","uri":"http://isure6.stream.qqmusic.qq.com/M500003t3LsR04jNft.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=381036FED7F420CEE38EE06AB68C38D9896E82981A16C51D75847A6488E76C1766CDC5071DD04461010527DBA8BBB5C0EC7CF472E098F439&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:02 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 31ms Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 16ms Apr 29 05:25:02 volumio volumio[8980]: info: sendMpdCommand status took 14 milliseconds Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 29 05:25:02 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:02 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:02 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:02 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":185,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"「千と千尋の神隠し」~いつも何度でも","artist":"久木田薫","album":"GHIBLI the Classics","uri":"http://isure6.stream.qqmusic.qq.com/M500003t3LsR04jNft.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=381036FED7F420CEE38EE06AB68C38D9896E82981A16C51D75847A6488E76C1766CDC5071DD04461010527DBA8BBB5C0EC7CF472E098F439&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:02 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:25:02 volumio volumio[8980]: info: Received an update from plugin. extracting info from payload Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:02 volumio volumio[8980]: info: ------------------------------ 42ms Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:02 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:02 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: Clearing queue after UPNP request Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::ClearQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::stop Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:25:04 volumio volumio[8980]: verbose: UNSET VOLATILE Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::updateTrackBlock Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getTrackBlock Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::serviceStop Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:04 volumio volumio[8980]: info: ControllerMpd::stop Apr 29 05:25:04 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::clearPlayQueue Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::saveQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:04 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:04 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:04 volumio volumio[8980]: info: sendMpdCommand stop took 103 milliseconds Apr 29 05:25:04 volumio volumio[8980]: info: Starting UPNP Playback Apr 29 05:25:04 volumio volumio[8980]: info: Preparing playback through UPNP Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:25:04 volumio volumio[8980]: error: updateQueue error: null Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 5ms Apr 29 05:25:04 volumio volumio[8980]: info: sendMpdCommand status took 4 milliseconds Apr 29 05:25:04 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:04 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:04 volumio volumio[8980]: 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} Apr 29 05:25:04 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::syncState stateService stop Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:04 volumio volumio[8980]: info: No code Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 24ms Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:04 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: Apr 29 05:25:04 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:04 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:04 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:05 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:25:05 volumio volumio[8980]: info: Apr 29 05:25:05 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:05 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:05 volumio volumio[8980]: info: Apr 29 05:25:05 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:05 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:05 volumio volumio[8980]: info: Apr 29 05:25:05 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:05 volumio volumio[8980]: info: sendMpdCommand status took 18 milliseconds Apr 29 05:25:05 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:05 volumio volumio[8980]: info: ------------------------------ 7ms Apr 29 05:25:05 volumio volumio[8980]: info: sendMpdCommand status took 5 milliseconds Apr 29 05:25:05 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:05 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:05 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:05 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Rinaldo HWV. 7 - Lascia Ch'io Pianga","artist":"Sarah Brightman","album":"Opera 2008","uri":"http://isure6.stream.qqmusic.qq.com/M500004fdxQB21Jk2v.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=0E0818A3D858A73C709BA9CBB5D62792FB42902B54BFA9ED80653628C39D18C538A551714EA55128146D1E0BDD0C438A30ADE5B03FCA2531&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:05 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:05 volumio volumio[8980]: info: ------------------------------ 41ms Apr 29 05:25:05 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 29 05:25:05 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:05 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:05 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:05 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":212,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Rinaldo HWV. 7 - Lascia Ch'io Pianga","artist":"Sarah Brightman","album":"Opera 2008","uri":"http://isure6.stream.qqmusic.qq.com/M500004fdxQB21Jk2v.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=0E0818A3D858A73C709BA9CBB5D62792FB42902B54BFA9ED80653628C39D18C538A551714EA55128146D1E0BDD0C438A30ADE5B03FCA2531&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:05 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:25:05 volumio volumio[8980]: info: Received an update from plugin. extracting info from payload Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:05 volumio volumio[8980]: info: ------------------------------ 41ms Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:05 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:05 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:05 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:05 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:05 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:12 volumio volumio[8980]: info: Clearing queue after UPNP request Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::ClearQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::stop Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:25:13 volumio volumio[8980]: verbose: UNSET VOLATILE Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::updateTrackBlock Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getTrackBlock Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::serviceStop Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::stop Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::clearPlayQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::saveQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:13 volumio volumio[8980]: info: sendMpdCommand stop took 64 milliseconds Apr 29 05:25:13 volumio volumio[8980]: info: Starting UPNP Playback Apr 29 05:25:13 volumio volumio[8980]: info: Preparing playback through UPNP Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:25:13 volumio volumio[8980]: error: updateQueue error: null Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 5ms Apr 29 05:25:13 volumio volumio[8980]: info: sendMpdCommand status took 4 milliseconds Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:13 volumio volumio[8980]: 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} Apr 29 05:25:13 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::syncState stateService stop Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: No code Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 21ms Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 1ms Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:13 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:25:13 volumio volumio[8980]: info: sendMpdCommand status took 14 milliseconds Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:13 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:13 volumio volumio[8980]: info: Apr 29 05:25:13 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:13 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:13 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:13 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":466,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"II. Adagio affettuoso","artist":"Jacqueline Du Pre","album":"勃拉姆斯2首大提琴奏鸣曲","uri":"http://isure6.stream.qqmusic.qq.com/M500004XAIeX1rvhwH.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=0EB1E232ADFC367893123A16CEF4DC825F6D5089BC9E6479B347BB3B99E049590785F33DB35A3C1486B6BEE21D483226343D4DF44D6B0E59&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:13 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 28ms Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 13ms Apr 29 05:25:13 volumio volumio[8980]: info: sendMpdCommand status took 49 milliseconds Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 29 05:25:13 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:13 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:13 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:13 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":466,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"II. Adagio affettuoso","artist":"Jacqueline Du Pre","album":"勃拉姆斯2首大提琴奏鸣曲","uri":"http://isure6.stream.qqmusic.qq.com/M500004XAIeX1rvhwH.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=0EB1E232ADFC367893123A16CEF4DC825F6D5089BC9E6479B347BB3B99E049590785F33DB35A3C1486B6BEE21D483226343D4DF44D6B0E59&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:13 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:25:13 volumio volumio[8980]: info: Received an update from plugin. extracting info from payload Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:13 volumio volumio[8980]: info: ------------------------------ 72ms Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:13 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:13 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:20 volumio volumio[8980]: info: Clearing queue after UPNP request Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::ClearQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::stop Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 05:25:20 volumio volumio[8980]: verbose: UNSET VOLATILE Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::stPlaybackTimer Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::updateTrackBlock Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getTrackBlock Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::serviceStop Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:20 volumio volumio[8980]: info: ControllerMpd::stop Apr 29 05:25:20 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand stop Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::clearPlayQueue Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::saveQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioPushQueue Apr 29 05:25:20 volumio volumio[8980]: info: Starting UPNP Playback Apr 29 05:25:20 volumio volumio[8980]: info: Preparing playback through UPNP Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioGetState Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 29 05:25:20 volumio volumio[8980]: info: Apr 29 05:25:20 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:20 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:20 volumio volumio[8980]: info: Apr 29 05:25:20 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:20 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:20 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:20 volumio volumio[8980]: info: sendMpdCommand stop took 57 milliseconds Apr 29 05:25:20 volumio volumio[8980]: error: updateQueue error: null Apr 29 05:25:20 volumio volumio[8980]: info: ------------------------------ 4ms Apr 29 05:25:20 volumio volumio[8980]: info: sendMpdCommand status took 2 milliseconds Apr 29 05:25:20 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:20 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getTrack 0 Apr 29 05:25:20 volumio volumio[8980]: 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} Apr 29 05:25:20 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::syncState stateService stop Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:20 volumio volumio[8980]: info: No code Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:20 volumio volumio[8980]: info: ------------------------------ 21ms Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:20 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:20 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 3ms Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 2ms Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:21 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:21 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 29 05:25:21 volumio volumio[8980]: info: sendMpdCommand status took 13 milliseconds Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces system playlist update Apr 29 05:25:21 volumio volumio[8980]: info: Ignoring MPD Status Update Apr 29 05:25:21 volumio volumio[8980]: info: Apr 29 05:25:21 volumio volumio[8980]: ---------------------------- MPD announces state update: player Apr 29 05:25:21 volumio volumio[8980]: info: ControllerMpd::getState Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand status Apr 29 05:25:21 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:21 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:21 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:21 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":229,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Million Years Ago (Violin Cover)","artist":"Bryson Andres","album":null,"uri":"http://isure6.stream.qqmusic.qq.com/M50000457Ok90aJozY.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=141CAA1180257CF7646A574831BF3163C770E42158EA821CE2771055D05904332CFDA6D6C72C1CE088ED6FB2C4B6726EBCC43AA0A121C182&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:21 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus stop Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 33ms Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 18ms Apr 29 05:25:21 volumio volumio[8980]: info: sendMpdCommand status took 17 milliseconds Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::parseState Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::volumioGetQueue Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::getQueue Apr 29 05:25:21 volumio volumio[8980]: info: CorePlayQueue::getQueue Apr 29 05:25:21 volumio volumio[8980]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 29 05:25:21 volumio volumio[8980]: verbose: ControllerMpd::parseTrackInfo Apr 29 05:25:21 volumio volumio[8980]: info: ControllerMpd::pushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::servicePushState Apr 29 05:25:21 volumio volumio[8980]: verbose: In UPNP mode Apr 29 05:25:21 volumio volumio[8980]: verbose: STATE SERVICE {"status":"play","position":0,"seek":487,"duration":229,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Million Years Ago (Violin Cover)","artist":"Bryson Andres","album":null,"uri":"http://isure6.stream.qqmusic.qq.com/M50000457Ok90aJozY.mp3?guid=B36106CE22DA41FB872922ED4279558F&vkey=141CAA1180257CF7646A574831BF3163C770E42158EA821CE2771055D05904332CFDA6D6C72C1CE088ED6FB2C4B6726EBCC43AA0A121C182&uin=1152921504689611133&redirect=1&fromtag=101042","trackType":""} Apr 29 05:25:21 volumio volumio[8980]: verbose: CURRENT POSITION 0 Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::syncState stateService play Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::syncState currentStatus play Apr 29 05:25:21 volumio volumio[8980]: info: Received an update from plugin. extracting info from payload Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:21 volumio volumio[8980]: info: CoreStateMachine::pushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::volumioPushState Apr 29 05:25:21 volumio volumio[8980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 05:25:21 volumio volumio[8980]: info: ------------------------------ 54ms Apr 29 05:25:21 volumio volumio[8980]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Bryson%20Andres/53ada7c9-61cf-40bf-97a4-f2e3726bfc2c.jpg' Apr 29 05:25:25 volumio volumio[8980]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 29 05:25:25 volumio volumio[8980]: { Error: connect ETIMEDOUT 108.160.166.57:443 Apr 29 05:25:25 volumio volumio[8980]: at Object._errnoException (util.js:1022:11) Apr 29 05:25:25 volumio volumio[8980]: at _exceptionWithHostPort (util.js:1044:20) Apr 29 05:25:25 volumio volumio[8980]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Apr 29 05:25:25 volumio volumio[8980]: code: 'ETIMEDOUT', Apr 29 05:25:25 volumio volumio[8980]: errno: 'ETIMEDOUT', Apr 29 05:25:25 volumio volumio[8980]: syscall: 'connect', Apr 29 05:25:25 volumio volumio[8980]: address: '108.160.166.57', Apr 29 05:25:25 volumio volumio[8980]: port: 443 } Apr 29 05:25:25 volumio volumio[8980]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 29 05:25:26 volumio sudo[9473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-29 05:24 Apr 29 05:25:26 volumio sudo[9473]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03" VOLUMIO_FE_VERSION="958dedc0edff114f244fa9acc70cf53089d9e5ae" VOLUMIO_BE_VERSION="fd3e37ffec12db034ec93f94dbc26e5495d5b91a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Oct 6 12:34:49 CEST 2021" VOLUMIO_VERSION="2.917" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="98c8f08c531a6f0456f17ab17795e35f"