Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:34 volumio volumio[1301]: info: Prefetching next song Aug 28 08:43:34 volumio volumio[1301]: info: DOING PREFETCH IN MPD Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand add "USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a" Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand add "USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a" took 1 milliseconds Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand consume 1 Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 1ms Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand consume 1 took 1 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 1ms Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 1ms Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 0ms Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces system playlist update Aug 28 08:43:34 volumio volumio[1301]: info: Ignoring MPD Status Update Aug 28 08:43:34 volumio volumio[1301]: info: Aug 28 08:43:34 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 2ms Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand status took 2 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 1ms Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand status took 1 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 1ms Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand status took 2 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 1ms Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand status took 1 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:34 volumio volumio[1301]: verbose: CURRENT POSITION 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState stateService play Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus play Aug 28 08:43:34 volumio volumio[1301]: info: Received an update from plugin. extracting info from payload Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:34 volumio volumio[1301]: verbose: CURRENT POSITION 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState stateService play Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus play Aug 28 08:43:34 volumio volumio[1301]: info: Received an update from plugin. extracting info from payload Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 8ms Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 7ms Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 28 08:43:34 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 6 milliseconds Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:34 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:34 volumio volumio[1301]: verbose: CURRENT POSITION 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState stateService play Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus play Aug 28 08:43:34 volumio volumio[1301]: info: Received an update from plugin. extracting info from payload Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:34 volumio volumio[1301]: verbose: CURRENT POSITION 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState stateService play Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus play Aug 28 08:43:34 volumio volumio[1301]: info: Received an update from plugin. extracting info from payload Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:34 volumio volumio[1301]: info: CorePlayQueue::getTrack 42 Aug 28 08:43:34 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 14ms Aug 28 08:43:34 volumio volumio[1301]: info: ------------------------------ 13ms Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:34 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:39 volumio volumio[1301]: info: CoreStateMachine::startPlaybackTimer Aug 28 08:43:39 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:39 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:39 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:39 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 08:43:39 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:39 volumio volumio[1301]: info: FusionDsp - Volumio is playing Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::volumioPause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::servicePause Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::servicePause Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::pause Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand pause Aug 28 08:43:47 volumio volumio[1301]: info: Aug 28 08:43:47 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand pause took 0 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:47 volumio volumio[1301]: info: Aug 28 08:43:47 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:47 volumio volumio[1301]: info: Aug 28 08:43:47 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:47 volumio volumio[1301]: info: Aug 28 08:43:47 volumio volumio[1301]: ---------------------------- MPD announces state update: player Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::getState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand status took 1 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand status took 0 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand status took 0 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand status took 0 milliseconds Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseState Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 28 08:43:47 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:47 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":12774,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:47 volumio volumio[1301]: verbose: CURRENT POSITION 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState stateService pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":12774,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:47 volumio volumio[1301]: verbose: CURRENT POSITION 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState stateService pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":12774,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:47 volumio volumio[1301]: verbose: CURRENT POSITION 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState stateService pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer Aug 28 08:43:47 volumio volumio[1301]: info: ControllerMpd::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::servicePushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":12774,"duration":209,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"258 Kbps","isStreaming":false,"title":"Mercy","artist":"Shawn Mendes","album":"Illuminate (Deluxe)","uri":"USB/446C-5B90/Billboard 2017 Year End Hot 100 Songs/054 Mercy.m4a","trackType":"m4a"} Aug 28 08:43:47 volumio volumio[1301]: verbose: CURRENT POSITION 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState stateService pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus pause Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::pushState Aug 28 08:43:47 volumio volumio[1301]: info: CorePlayQueue::getTrack 103 Aug 28 08:43:47 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState Aug 28 08:43:47 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer Aug 28 08:43:47 volumio volumio[1301]: info: ------------------------------ 5ms Aug 28 08:43:47 volumio volumio[1301]: info: ------------------------------ 4ms Aug 28 08:43:47 volumio volumio[1301]: info: ------------------------------ 4ms Aug 28 08:43:47 volumio volumio[1301]: info: ------------------------------ 4ms Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Volumio is not playing Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Volumio is not playing Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Volumio is not playing Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Volumio is not playing Aug 28 08:43:47 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped Aug 28 08:43:48 volumio volumio[1301]: info: camilladsp respawn in 100 ms (attempt 1/10) Aug 28 08:43:57 volumio nmbd[1239]: [2026/08/28 08:43:57.092784, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 28 08:43:57 volumio nmbd[1239]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.30 for name WORKGROUP<1d>. Aug 28 08:43:57 volumio nmbd[1239]: This response was from IP 192.168.0.10, reporting an IP address of 192.168.0.10. Aug 28 08:43:57 volumio nmbd[1239]: [2026/08/28 08:43:57.093005, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 28 08:43:57 volumio nmbd[1239]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.0.30 for name WORKGROUP<1d>. Aug 28 08:43:57 volumio nmbd[1239]: This response was from IP 192.168.0.3, reporting an IP address of 192.168.0.42. Aug 28 08:43:57 volumio nmbd[1239]: [2026/08/28 08:43:57.095866, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 28 08:43:57 volumio nmbd[1239]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.0.30 for name WORKGROUP<1d>. Aug 28 08:43:57 volumio nmbd[1239]: This response was from IP 192.168.0.10, reporting an IP address of 192.168.0.10. Aug 28 08:44:16 volumio systemd-logind[881]: Power key pressed short. Aug 28 08:44:16 volumio systemd-logind[881]: Powering off... Aug 28 08:44:16 volumio systemd-logind[881]: System is powering down. Aug 28 08:44:16 volumio systemd[1]: Removed slice system-modprobe.slice - Slice /system/modprobe. Aug 28 08:44:16 volumio systemd[1]: Stopped target bluetooth.target - Bluetooth Support. Aug 28 08:44:16 volumio systemd[1]: Stopped target graphical.target - Graphical Interface. Aug 28 08:44:16 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Aug 28 08:44:16 volumio systemd[1]: Stopped target multi-user.target - Multi-User System. Aug 28 08:44:16 volumio systemd[1]: Stopped target getty.target - Login Prompts. Aug 28 08:44:16 volumio systemd[1]: Stopped target rpc_pipefs.target. Aug 28 08:44:16 volumio systemd[1]: Stopped target rpcbind.target - RPC Port Mapper. Aug 28 08:44:16 volumio systemd[1]: Stopped target timers.target - Timer Units. Aug 28 08:44:16 volumio systemd[1]: apt-daily-upgrade.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped apt-daily-upgrade.timer - Daily apt upgrade and clean activities. Aug 28 08:44:16 volumio systemd[1]: apt-daily.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped apt-daily.timer - Daily apt download activities. Aug 28 08:44:16 volumio systemd[1]: dpkg-db-backup.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped dpkg-db-backup.timer - Daily dpkg database backup timer. Aug 28 08:44:16 volumio systemd[1]: e2scrub_all.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped e2scrub_all.timer - Periodic ext4 Online Metadata Check for All Filesystems. Aug 28 08:44:16 volumio systemd[1]: fstrim.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped fstrim.timer - Discard unused blocks once a week. Aug 28 08:44:16 volumio systemd[1]: man-db.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped man-db.timer - Daily man-db regeneration. Aug 28 08:44:16 volumio systemd[1]: ntpsec-rotate-stats.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped ntpsec-rotate-stats.timer - Rotate ntpd stats daily. Aug 28 08:44:16 volumio systemd[1]: setdatetime-helper.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped setdatetime-helper.timer - Volumio Time Sync Watchdog Timer. Aug 28 08:44:16 volumio systemd[1]: systemd-tmpfiles-clean.timer: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped systemd-tmpfiles-clean.timer - Daily Cleanup of Temporary Directories. Aug 28 08:44:16 volumio systemd[1]: systemd-rfkill.socket: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Closed systemd-rfkill.socket - Load/Save RF Kill Switch Status /dev/rfkill Watch. Aug 28 08:44:16 volumio systemd[1]: Unmounting run-rpc_pipefs.mount - RPC Pipe File System... Aug 28 08:44:16 volumio systemd[1]: Stopping acpid.service - ACPI event daemon... Aug 28 08:44:16 volumio systemd[1]: Stopping bluealsa.service - BlueALSA service... Aug 28 08:44:16 volumio bluealsa[926]: (../../../gio/gdbusobjectmanagerserver.c:1168):unexport_all: runtime check failed: (manager->priv->manager_reg_id > 0) Aug 28 08:44:16 volumio bluetoothd[876]: Endpoint unregistered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/source/1 Aug 28 08:44:16 volumio systemd[1]: Stopping cpufrequtils.service - LSB: set CPUFreq kernel parameters... Aug 28 08:44:16 volumio volumio[2130]: ======== Running on http://0.0.0.0:5011 ======== Aug 28 08:44:16 volumio volumio[2130]: (Press CTRL+C to quit) Aug 28 08:44:16 volumio bluetoothd[876]: Endpoint unregistered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/sink/2 Aug 28 08:44:16 volumio systemd[1]: Stopping fusiondsp.service - FusionDsp Daemon... Aug 28 08:44:16 volumio bluetoothd[876]: Endpoint unregistered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/source/2 Aug 28 08:44:16 volumio systemd[1]: Stopping getty@tty1.service - Getty on tty1... Aug 28 08:44:16 volumio bluetoothd[876]: Endpoint unregistered: sender=:1.5 path=/org/bluez/hci0/A2DP/SBC/sink/1 Aug 28 08:44:16 volumio systemd[1]: Stopping ifplugd.service - LSB: Brings up/down network automatically... Aug 28 08:44:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 28 08:44:16 volumio ntpd[1172]: ERR: ntpd exiting on signal 15 (Terminated) Aug 28 08:44:16 volumio ntpd[1172]: PROTO: 198.18.0.182 unlink local addr 192.168.0.30 -> Aug 28 08:44:16 volumio systemd[1]: Stopping ntpsec.service - Network Time Service... Aug 28 08:44:16 volumio ntpd[1172]: PROTO: 198.18.0.183 unlink local addr 192.168.0.30 -> Aug 28 08:44:16 volumio systemd[1]: plymouth-quit.service: Deactivated successfully. Aug 28 08:44:16 volumio ntpd[1172]: PROTO: 198.18.0.188 unlink local addr 192.168.0.30 -> Aug 28 08:44:16 volumio systemd[1]: Stopped plymouth-quit.service - Terminate Plymouth Boot Screen. Aug 28 08:44:16 volumio ntpd[1172]: PROTO: 198.18.0.194 unlink local addr 192.168.0.30 -> Aug 28 08:44:16 volumio systemd[1]: Stopping screenshot.service - Process screenshots triggered by PrtSc-button... Aug 28 08:44:16 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 28 08:44:16 volumio systemd[1]: Stopping smbd.service - Samba SMB Daemon... Aug 28 08:44:16 volumio systemd[1]: Stopping systemd-logind.service - User Login Management... Aug 28 08:44:16 volumio systemd[1]: Stopping systemd-random-seed.service - Load/Save Random Seed... Aug 28 08:44:16 volumio systemd[1]: Stopping triggerhappy.service - triggerhappy global hotkey daemon... Aug 28 08:44:16 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Aug 28 08:44:16 volumio systemd[1]: Stopping volumio-ipchange.service - Volumio IP Change Monitor... Aug 28 08:44:16 volumio systemd[1]: Stopping volumio-kiosk.service - Start Volumio Kiosk... Aug 28 08:44:16 volumio systemd[1]: Stopping volumio-remote-updater.service - Volumio Remote OTA Updater... Aug 28 08:44:16 volumio systemd[1]: Stopping volumio5-onboarding.service - Volumio5 Onboarding Server... Aug 28 08:44:16 volumio systemd[1]: welcome.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Aug 28 08:44:16 volumio startx[1369]: xinit: connection to X server lost Aug 28 08:44:16 volumio startx[1369]: Aug 28 08:44:16 volumio systemd[1]: volumio-remote-updater.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped volumio-remote-updater.service - Volumio Remote OTA Updater. Aug 28 08:44:16 volumio systemd[1]: bluealsa.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped bluealsa.service - BlueALSA service. Aug 28 08:44:16 volumio systemd[1]: volumio-ipchange.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped volumio-ipchange.service - Volumio IP Change Monitor. Aug 28 08:44:16 volumio systemd[1]: ntpsec.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped ntpsec.service - Network Time Service. Aug 28 08:44:16 volumio systemd[1]: ntpsec.service: Consumed 2.591s CPU time. Aug 28 08:44:16 volumio systemd[1]: getty@tty1.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped getty@tty1.service - Getty on tty1. Aug 28 08:44:16 volumio systemd[1]: screenshot.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped screenshot.service - Process screenshots triggered by PrtSc-button. Aug 28 08:44:16 volumio systemd[1]: screenshot.service: Consumed 1min 24.825s CPU time. Aug 28 08:44:16 volumio systemd[1]: smbd.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped smbd.service - Samba SMB Daemon. Aug 28 08:44:16 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 28 08:44:16 volumio systemd[1]: shairport-sync.service: Consumed 4min 57.518s CPU time. Aug 28 08:44:16 volumio systemd[1]: volumio5-onboarding.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Aug 28 08:44:16 volumio systemd[1]: volumio5-onboarding.service: Consumed 13.829s CPU time. Aug 28 08:44:16 volumio systemd[1]: run-rpc_pipefs.mount: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Unmounted run-rpc_pipefs.mount - RPC Pipe File System. Aug 28 08:44:16 volumio systemd[1]: Removed slice system-getty.slice - Slice /system/getty. Aug 28 08:44:16 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Aug 28 08:44:16 volumio systemd[1]: Stopping bluetooth.service - Bluetooth service... Aug 28 08:44:16 volumio avahi-daemon[875]: Got SIGTERM, quitting. Aug 28 08:44:16 volumio avahi-daemon[875]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Aug 28 08:44:16 volumio avahi-daemon[875]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.0.30. Aug 28 08:44:16 volumio bluetoothd[876]: Terminating Aug 28 08:44:16 volumio volumio[1301]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 08:44:16 volumio volumio[1301]: Error: dns service error: unknown Aug 28 08:44:16 volumio volumio[1301]: at Browser.on_service_changed (/volumio/node_modules/mdns/lib/browser.js:84:33) Aug 28 08:44:16 volumio volumio[1301]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Aug 28 08:44:16 volumio volumio[1301]: errorCode: -65537 Aug 28 08:44:16 volumio volumio[1301]: } Aug 28 08:44:16 volumio volumio[1301]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 08:44:16 volumio systemd[1]: Starting plymouth-poweroff.service - Show Plymouth Power Off Screen... Aug 28 08:44:16 volumio systemd[1]: plymouth-quit-wait.service: Deactivated successfully. Aug 28 08:44:16 volumio avahi-daemon[875]: avahi-daemon 0.8 exiting. Aug 28 08:44:16 volumio systemd[1]: Stopped plymouth-quit-wait.service - Hold until boot process finishes up. Aug 28 08:44:16 volumio systemd[1]: rc-local.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped rc-local.service - /etc/rc.local Compatibility. Aug 28 08:44:16 volumio systemd[1]: Stopping systemd-user-sessions.service - Permit User Sessions... Aug 28 08:44:16 volumio winbindd[1627]: [2026/08/28 08:44:16.149919, 0] ../../source3/winbindd/winbindd_dual.c:1954(winbindd_sig_term_handler) Aug 28 08:44:16 volumio winbindd[1627]: Got sig[15] terminate (is_parent=1) Aug 28 08:44:16 volumio winbindd[1630]: [2026/08/28 08:44:16.150337, 0] ../../source3/winbindd/winbindd_dual.c:1954(winbindd_sig_term_handler) Aug 28 08:44:16 volumio winbindd[1630]: Got sig[15] terminate (is_parent=0) Aug 28 08:44:16 volumio systemd[1]: Stopping winbind.service - Samba Winbind Daemon... Aug 28 08:44:16 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Aug 28 08:44:16 volumio systemd[1]: systemd-logind.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped systemd-logind.service - User Login Management. Aug 28 08:44:16 volumio systemd[1]: winbind.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped winbind.service - Samba Winbind Daemon. Aug 28 08:44:16 volumio systemd[1]: winbind.service: Consumed 2.188s CPU time. Aug 28 08:44:16 volumio systemd[1]: systemd-random-seed.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped systemd-random-seed.service - Load/Save Random Seed. Aug 28 08:44:16 volumio systemd[1]: Received SIGRTMIN+20 from PID 135778 (plymouthd). Aug 28 08:44:16 volumio systemd[1]: fusiondsp.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Aug 28 08:44:16 volumio systemd[1]: fusiondsp.service: Consumed 1.259s CPU time. Aug 28 08:44:16 volumio nmbd[1239]: [2026/08/28 08:44:16.166579, 0] ../../source3/nmbd/nmbd.c:59(terminate) Aug 28 08:44:16 volumio nmbd[1239]: Got SIGTERM: going down... Aug 28 08:44:16 volumio systemd[1]: Stopping nmbd.service - Samba NMB Daemon... Aug 28 08:44:16 volumio systemd[1]: nmbd.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped nmbd.service - Samba NMB Daemon. Aug 28 08:44:16 volumio systemd[1]: nmbd.service: Consumed 6.391s CPU time. Aug 28 08:44:16 volumio systemd[1]: systemd-user-sessions.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped systemd-user-sessions.service - Permit User Sessions. Aug 28 08:44:16 volumio systemd[1]: mpd.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 28 08:44:16 volumio systemd[1]: mpd.service: Consumed 1min 16.795s CPU time. Aug 28 08:44:16 volumio systemd[1]: Stopped target sound.target - Sound Card. Aug 28 08:44:16 volumio bluetoothd[876]: Destroy Adv Monitor Manager Aug 28 08:44:16 volumio bluetoothd[876]: Battery Provider Manager destroyed Aug 28 08:44:16 volumio bluetoothd[876]: Stopping SDP server Aug 28 08:44:16 volumio bluetoothd[876]: Exit Aug 28 08:44:16 volumio systemd[1]: bluetooth.service: Deactivated successfully. Aug 28 08:44:16 volumio systemd[1]: Stopped bluetooth.service - Bluetooth service. Aug 28 08:44:16 volumio systemd[1]: bluetooth.service: Consumed 4.044s CPU time. Aug 28 08:44:16 volumio sudo[135790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-28 08:43' Aug 28 08:44:16 volumio sudo[135790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"