-- Logs begin at Thu 2019-02-14 10:11:58 UTC, end at Tue 2025-11-04 06:37:37 UTC. -- Nov 04 06:36:12 localhost volumio[21196]: info: Nov 04 06:36:12 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:12 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:12 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:12 localhost volumio[21196]: info: sendMpdCommand status took 2 milliseconds Nov 04 06:36:12 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:12 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:12 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 04 06:36:12 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:12 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:12 localhost volumio[21196]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Carmen 44kHz","artist":"Carmen","album":"RMAF 2010","uri":"http://192.168.57.108:52100/Music/F959.flac","trackType":"flac"} Nov 04 06:36:12 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:12 localhost volumio[21196]: error: ControllerMpd::pushError: TypeError: Cannot read property 'indexOf' of null Nov 04 06:36:12 localhost volumio[21196]: info: ------------------------------ 40ms Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:36:12 localhost volumio[21196]: info: Clearing queue after UPNP request Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::ClearQueue Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::updateTrackBlock Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::getTrackBlock Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::serviceStop Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:12 localhost volumio[21196]: info: ControllerMpd::stop Nov 04 06:36:12 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand stop Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::clearPlayQueue Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::saveQueue Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioPushQueue Nov 04 06:36:12 localhost volumio[21196]: info: Nov 04 06:36:12 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:12 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:12 localhost volumio[21196]: info: sendMpdCommand stop took 26 milliseconds Nov 04 06:36:12 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:36:12 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:12 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:36:12 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:36:12 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:36:12 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:12 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:12 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:36:12 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:13 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:13 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:13 localhost volumio[21196]: info: Nov 04 06:36:13 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:13 localhost volumio[21196]: info: sendMpdCommand status took 112 milliseconds Nov 04 06:36:13 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 57ms Nov 04 06:36:13 localhost volumio[21196]: info: sendMpdCommand status took 16 milliseconds Nov 04 06:36:13 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 12 milliseconds Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:13 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:13 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:13 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":182,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(192kHz)Divertimento 192-24","artist":"TrondheimSolistene","album":"DIVERTIMENTI","uri":"http://192.168.57.108:52100/Music/F6284.flac","trackType":"flac"} Nov 04 06:36:13 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus stop Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 159ms Nov 04 06:36:13 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 20 milliseconds Nov 04 06:36:13 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:13 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:13 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:13 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":182,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3663 Kbps","isStreaming":false,"title":"(192kHz)Divertimento 192-24","artist":"TrondheimSolistene","album":"DIVERTIMENTI","uri":"http://192.168.57.108:52100/Music/F6284.flac","trackType":"flac"} Nov 04 06:36:13 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:36:13 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:13 localhost volumio[21196]: info: ------------------------------ 109ms Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:36:13 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:36:13 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:36:13 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:36:13 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:36:14 localhost volumio[21196]: info: MetaClient: Sent Meta Nov 04 06:36:14 localhost node[422]: metadata_handler Nov 04 06:36:14 localhost volumio[21196]: info: MetaClient: Get message: success Nov 04 06:36:19 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:36:19 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:36:19 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:36:19 localhost volumio[21196]: info: Consume mode Nov 04 06:36:19 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:19 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:36:19 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:36:19 localhost volumio[21196]: info: Nov 04 06:36:19 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:19 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:19 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:19 localhost volumio[21196]: info: Nov 04 06:36:19 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:19 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:19 localhost volumio[21196]: info: ------------------------------ 8ms Nov 04 06:36:19 localhost volumio[21196]: info: Nov 04 06:36:19 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:19 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:19 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:19 localhost volumio[21196]: info: Nov 04 06:36:19 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:19 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:19 localhost volumio[21196]: info: ------------------------------ 20ms Nov 04 06:36:19 localhost volumio[21196]: info: Nov 04 06:36:19 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:19 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:19 localhost volumio[21196]: info: ------------------------------ 26ms Nov 04 06:36:19 localhost volumio[21196]: info: Nov 04 06:36:19 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:19 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:19 localhost volumio[21196]: info: ------------------------------ 21ms Nov 04 06:36:21 localhost volumio[21196]: info: Nov 04 06:36:21 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:21 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:21 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:21 localhost volumio[21196]: info: sendMpdCommand status took 2 milliseconds Nov 04 06:36:21 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:21 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:21 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:21 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 04 06:36:21 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:21 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:21 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:21 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:21 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:21 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:21 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:21 localhost volumio[21196]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(192kHz)Divertimento 192-24","artist":"TrondheimSolistene","album":"DIVERTIMENTI","uri":"http://192.168.57.108:52100/Music/F6284.flac","trackType":"flac"} Nov 04 06:36:21 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:21 localhost volumio[21196]: error: ControllerMpd::pushError: TypeError: Cannot read property 'indexOf' of null Nov 04 06:36:21 localhost volumio[21196]: info: ------------------------------ 33ms Nov 04 06:36:21 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:36:21 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:36:21 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:36:22 localhost volumio[21196]: info: Clearing queue after UPNP request Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::ClearQueue Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::updateTrackBlock Nov 04 06:36:22 localhost volumio[21196]: info: CorePlayQueue::getTrackBlock Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:22 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::serviceStop Nov 04 06:36:22 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:22 localhost volumio[21196]: info: ControllerMpd::stop Nov 04 06:36:22 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand stop Nov 04 06:36:22 localhost volumio[21196]: info: CorePlayQueue::clearPlayQueue Nov 04 06:36:22 localhost volumio[21196]: info: CorePlayQueue::saveQueue Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::volumioPushQueue Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: sendMpdCommand stop took 27 milliseconds Nov 04 06:36:22 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:22 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:36:22 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:36:22 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:36:22 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:22 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:22 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:36:22 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 9ms Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:22 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:22 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:22 localhost volumio[21196]: info: Nov 04 06:36:22 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:22 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:22 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:23 localhost volumio[21196]: info: sendMpdCommand status took 96 milliseconds Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:23 localhost volumio[21196]: info: Nov 04 06:36:23 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:23 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:23 localhost volumio[21196]: info: Nov 04 06:36:23 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:23 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:23 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 15 milliseconds Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:23 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:23 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:23 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":183,"samplerate":"352.8 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(352kHz)Divertimento 352.8-24","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F965.flac","trackType":"flac"} Nov 04 06:36:23 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:23 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:23 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus stop Nov 04 06:36:23 localhost volumio[21196]: info: ------------------------------ 137ms Nov 04 06:36:23 localhost volumio[21196]: info: ------------------------------ 33ms Nov 04 06:36:23 localhost volumio[21196]: info: sendMpdCommand status took 23 milliseconds Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:23 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 04 06:36:23 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:23 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:23 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:23 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":524,"duration":183,"samplerate":"352.8 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"8789 Kbps","isStreaming":false,"title":"(352kHz)Divertimento 352.8-24","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F965.flac","trackType":"flac"} Nov 04 06:36:23 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:23 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:23 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:36:23 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:36:23 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:23 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:23 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:23 localhost volumio[21196]: info: ------------------------------ 85ms Nov 04 06:36:24 localhost node[422]: metadata_handler Nov 04 06:36:24 localhost volumio[21196]: info: MetaClient: Sent Meta Nov 04 06:36:24 localhost volumio[21196]: info: MetaClient: Get message: success Nov 04 06:36:30 localhost volumio[21196]: info: Nov 04 06:36:30 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:30 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:30 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:30 localhost volumio[21196]: info: sendMpdCommand status took 2 milliseconds Nov 04 06:36:30 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:30 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:30 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:30 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 04 06:36:30 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:30 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:30 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:30 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:30 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:30 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:30 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:30 localhost volumio[21196]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(352kHz)Divertimento 352.8-24","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F965.flac","trackType":"flac"} Nov 04 06:36:30 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:30 localhost volumio[21196]: error: ControllerMpd::pushError: TypeError: Cannot read property 'indexOf' of null Nov 04 06:36:30 localhost volumio[21196]: info: ------------------------------ 33ms Nov 04 06:36:30 localhost volumio[21196]: info: Clearing queue after UPNP request Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::ClearQueue Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::updateTrackBlock Nov 04 06:36:31 localhost volumio[21196]: info: CorePlayQueue::getTrackBlock Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:31 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::serviceStop Nov 04 06:36:31 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:31 localhost volumio[21196]: info: ControllerMpd::stop Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand stop Nov 04 06:36:31 localhost volumio[21196]: info: CorePlayQueue::clearPlayQueue Nov 04 06:36:31 localhost volumio[21196]: info: CorePlayQueue::saveQueue Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::volumioPushQueue Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: sendMpdCommand stop took 26 milliseconds Nov 04 06:36:31 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:31 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:36:31 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:36:31 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:31 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:36:31 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 7ms Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:31 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:31 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:31 localhost volumio[21196]: info: sendMpdCommand status took 96 milliseconds Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:31 localhost volumio[21196]: info: Nov 04 06:36:31 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:31 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:31 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:31 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:31 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:31 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":182,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(DSD128)Divertimento DSD128","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F939.dff","trackType":"dff"} Nov 04 06:36:31 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:31 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus stop Nov 04 06:36:31 localhost volumio[21196]: info: ------------------------------ 157ms Nov 04 06:36:31 localhost volumio[21196]: info: sendMpdCommand status took 50 milliseconds Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:31 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 04 06:36:31 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:31 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:31 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:31 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":182,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(DSD128)Divertimento DSD128","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F939.dff","trackType":"dff"} Nov 04 06:36:31 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:31 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:36:32 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:32 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:36:32 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:36:32 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:32 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:32 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:32 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:32 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:32 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:32 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:32 localhost volumio[21196]: info: ------------------------------ 166ms Nov 04 06:36:33 localhost node[422]: metadata_handler Nov 04 06:36:33 localhost volumio[21196]: info: MetaClient: Sent Meta Nov 04 06:36:33 localhost volumio[21196]: info: MetaClient: Get message: success Nov 04 06:36:37 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:36:37 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:36:37 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:36:37 localhost volumio[21196]: info: Consume mode Nov 04 06:36:37 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:37 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:36:37 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:38 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 8ms Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:38 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:38 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:38 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:38 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:38 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:36:38 localhost volumio[21196]: info: Nov 04 06:36:38 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:38 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:38 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:38 localhost volumio[21196]: info: sendMpdCommand status took 2 milliseconds Nov 04 06:36:38 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:38 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:38 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:38 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 04 06:36:38 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:38 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:38 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:38 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:38 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:38 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:38 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:38 localhost volumio[21196]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(DSD128)Divertimento DSD128","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F939.dff","trackType":"dff"} Nov 04 06:36:38 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:38 localhost volumio[21196]: error: ControllerMpd::pushError: TypeError: Cannot read property 'indexOf' of null Nov 04 06:36:38 localhost volumio[21196]: info: ------------------------------ 31ms Nov 04 06:36:39 localhost volumio[21196]: info: Clearing queue after UPNP request Nov 04 06:36:39 localhost node[422]: metadata_handler Nov 04 06:36:39 localhost volumio[21196]: info: MetaClient: Sent Meta Nov 04 06:36:39 localhost volumio[21196]: info: MetaClient: Get message: success Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::ClearQueue Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::updateTrackBlock Nov 04 06:36:39 localhost volumio[21196]: info: CorePlayQueue::getTrackBlock Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:39 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::serviceStop Nov 04 06:36:39 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:39 localhost volumio[21196]: info: ControllerMpd::stop Nov 04 06:36:39 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand stop Nov 04 06:36:39 localhost volumio[21196]: info: CorePlayQueue::clearPlayQueue Nov 04 06:36:39 localhost volumio[21196]: info: CorePlayQueue::saveQueue Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::volumioPushQueue Nov 04 06:36:39 localhost volumio[21196]: info: Nov 04 06:36:39 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:39 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:39 localhost volumio[21196]: info: sendMpdCommand stop took 26 milliseconds Nov 04 06:36:39 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:36:39 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:39 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:36:39 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:36:39 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:36:39 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:39 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:36:39 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:36:39 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:40 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:40 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 6ms Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:40 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:40 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:40 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:36:40 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:40 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:40 localhost volumio[21196]: info: Nov 04 06:36:40 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:36:40 localhost volumio[21196]: info: sendMpdCommand status took 85 milliseconds Nov 04 06:36:40 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:40 localhost volumio[21196]: info: sendMpdCommand status took 9 milliseconds Nov 04 06:36:40 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 5 milliseconds Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:40 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:40 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:40 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":198,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(DSD256)k4","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F940.dff","trackType":"dff"} Nov 04 06:36:40 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:36:40 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:40 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus stop Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 142ms Nov 04 06:36:40 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 47 milliseconds Nov 04 06:36:40 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:36:40 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:36:40 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:36:40 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":198,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(DSD256)k4","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F940.dff","trackType":"dff"} Nov 04 06:36:40 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:36:40 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:36:40 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:36:40 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:36:40 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:40 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:36:40 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:36:40 localhost volumio[21196]: info: ------------------------------ 141ms Nov 04 06:36:41 localhost node[422]: metadata_handler Nov 04 06:36:41 localhost volumio[21196]: info: MetaClient: Sent Meta Nov 04 06:36:41 localhost volumio[21196]: info: MetaClient: Get message: success Nov 04 06:36:46 localhost systemd[1]: Starting Internet Detect for iFi Streamer... Nov 04 06:36:46 localhost systemd[1]: ifi-system-internet.service: Succeeded. Nov 04 06:36:46 localhost systemd[1]: Started Internet Detect for iFi Streamer. Nov 04 06:37:13 localhost volumio[21196]: info: Nov 04 06:37:13 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:13 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:13 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:13 localhost volumio[21196]: info: sendMpdCommand status took 2 milliseconds Nov 04 06:37:13 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:13 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:13 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:13 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 04 06:37:13 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:13 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:13 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:13 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:37:13 localhost volumio[21196]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":33899,"duration":198,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"22579 Kbps","isStreaming":false,"title":"(DSD256)k4","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F940.dff","trackType":"dff"} Nov 04 06:37:13 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:13 localhost volumio[21196]: info: CoreStateMachine::syncState stateService pause Nov 04 06:37:13 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:37:13 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:13 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:13 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:13 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:37:13 localhost volumio[21196]: info: ------------------------------ 54ms Nov 04 06:37:18 localhost kernel: usb 4-1.1: USB disconnect, device number 4 Nov 04 06:37:18 localhost systemd[1]: Starting Internet Detect for iFi Streamer... Nov 04 06:37:18 localhost volumio[21196]: info: Nov 04 06:37:18 localhost volumio[21196]: ---------------------------- USB Audio Device Detached Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::Close All Modals sent Nov 04 06:37:18 localhost volumio[21196]: info: Preparing to save Alsa Options, stopping services first Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::volumioPause Nov 04 06:37:18 localhost volumio[21196]: info: CoreStateMachine::pause Nov 04 06:37:18 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:37:18 localhost volumio[21196]: info: CoreStateMachine::servicePause Nov 04 06:37:18 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:18 localhost volumio[21196]: info: Error: no service or no trackblock to pause Nov 04 06:37:18 localhost volumio[21196]: info: Saving Audio Output to: {"disallowPush":false,"output_device":{"value":"0,0","label":"SPDIF"}} Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , forceDoP Nov 04 06:37:18 localhost systemd[1]: ifi-system-internet.service: Succeeded. Nov 04 06:37:18 localhost systemd[1]: Started Internet Detect for iFi Streamer. Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 06:37:18 localhost volumio[21196]: info: Found match in Cards Database: setting mixer for card SPDIF Nov 04 06:37:18 localhost volumio[21196]: info: Ignoring Mixers Options Nov 04 06:37:18 localhost volumio[21196]: info: Device 0,0 does not have any Mixer Control Available Nov 04 06:37:18 localhost volumio[21196]: info: Restoring Previous Volume level: 100 false false Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 04 06:37:18 localhost volumio[21196]: info: Updating Volume Controller Parameters: Device: 0,0 Name: SPDIF Mixer: None Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Nov 04 06:37:18 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:18 localhost volumio[21196]: info: Preparing to generate the ALSA configuration file Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: wizard , refreshWizarOutputDevices Nov 04 06:37:18 localhost volumio[21196]: info: Asound.conf file written Nov 04 06:37:18 localhost sudo[26673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 04 06:37:18 localhost sudo[26673]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:18 localhost sudo[26673]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:18 localhost volumio[21196]: No state is present for card rkifispdif Nov 04 06:37:18 localhost volumio[21196]: Found hardware: "rk-ifi-spdif" "" "" "" "" Nov 04 06:37:18 localhost volumio[21196]: Hardware is initialized using a generic method Nov 04 06:37:18 localhost volumio[21196]: No state is present for card rkifispdif Nov 04 06:37:18 localhost volumio[21196]: info: Tidal connect: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Output device has changed, restarting MPD Nov 04 06:37:18 localhost volumio[21196]: info: Qobuz connect: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Roon Ready: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Spotify: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Tidal connect: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Output device has changed, restarting MPD Nov 04 06:37:18 localhost sudo[26678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 04 06:37:18 localhost sudo[26678]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:18 localhost sudo[26678]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:18 localhost volumio[21196]: info: Qobuz connect: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Roon Ready: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: Spotify: Output device has changed Nov 04 06:37:18 localhost volumio[21196]: info: MPD Permissions set Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost sudo[26681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 04 06:37:18 localhost sudo[26681]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:18 localhost sudo[26681]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 06:37:18 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 06:37:19 localhost volumio[21196]: info: MPD Permissions set Nov 04 06:37:19 localhost volumio[21196]: info: Starting RoonReady Sync Nov 04 06:37:19 localhost sudo[26696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop ifi-streamer-qobuz-connect.service Nov 04 06:37:19 localhost sudo[26696]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:19 localhost volumio[21196]: info: Starting RoonReady Sync Nov 04 06:37:19 localhost sudo[26698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart ifi-streamer-roon-ready.service Nov 04 06:37:19 localhost sudo[26698]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:19 localhost systemd[1]: Stopping iFi Streamer Qobuz Connect Service... Nov 04 06:37:19 localhost node[422]: Closing connection with the client qobuz-connect Nov 04 06:37:19 localhost node[466]: ConvSwitch: Drop client qobuz-connect Nov 04 06:37:19 localhost systemd[1]: ifi-streamer-qobuz-connect.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:19 localhost systemd[1]: ifi-streamer-qobuz-connect.service: Succeeded. Nov 04 06:37:19 localhost systemd[1]: Stopped iFi Streamer Qobuz Connect Service. Nov 04 06:37:19 localhost sudo[26696]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:19 localhost sudo[26703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop ifi-streamer-qobuz-connect.service Nov 04 06:37:19 localhost sudo[26703]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:19 localhost sudo[26704]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart ifi-streamer-roon-ready.service Nov 04 06:37:19 localhost sudo[26704]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:19 localhost systemd[1]: Stopping iFi Streamer Roon Ready Service... Nov 04 06:37:19 localhost node[466]: ConvSwitch: Drop client roon-ready Nov 04 06:37:19 localhost node[422]: Closing connection with the client roon-ready Nov 04 06:37:19 localhost systemd[1]: ifi-streamer-roon-ready.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:19 localhost systemd[1]: ifi-streamer-roon-ready.service: Succeeded. Nov 04 06:37:19 localhost systemd[1]: Stopped iFi Streamer Roon Ready Service. Nov 04 06:37:19 localhost systemd[1]: Started iFi Streamer Roon Ready Service. Nov 04 06:37:19 localhost sudo[26698]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:19 localhost volumio[21196]: info: RoonReady Started Nov 04 06:37:19 localhost play[26707]: /usr/ifi/ifi-roonready-release/play: line 18: warning: command substitution: ignored null byte in input Nov 04 06:37:19 localhost systemd[1]: Stopping iFi Streamer Roon Ready Service... Nov 04 06:37:19 localhost systemd[1]: ifi-streamer-roon-ready.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:19 localhost systemd[1]: ifi-streamer-roon-ready.service: Succeeded. Nov 04 06:37:19 localhost systemd[1]: Stopped iFi Streamer Roon Ready Service. Nov 04 06:37:19 localhost sudo[26703]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:19 localhost systemd[1]: Started iFi Streamer Roon Ready Service. Nov 04 06:37:19 localhost sudo[26704]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:19 localhost volumio[21196]: info: RoonReady Started Nov 04 06:37:19 localhost play[26712]: /usr/ifi/ifi-roonready-release/play: line 18: warning: command substitution: ignored null byte in input Nov 04 06:37:19 localhost node[466]: ConvSwitch: Add client roon-ready Nov 04 06:37:19 localhost volumio[21196]: info: ConvSwitch: Get message: request:pause Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::volumioStop Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::updateTrackBlock Nov 04 06:37:19 localhost volumio[21196]: info: CorePlayQueue::getTrackBlock Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::stPlaybackTimer Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:19 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::serviceStop Nov 04 06:37:19 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:19 localhost volumio[21196]: info: ControllerMpd::stop Nov 04 06:37:19 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand stop Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::volumioStop Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:19 localhost volumio[21196]: info: Nov 04 06:37:19 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:19 localhost volumio[21196]: info: sendMpdCommand stop took 14 milliseconds Nov 04 06:37:19 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:19 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:19 localhost volumio[21196]: info: sendMpdCommand status took 2 milliseconds Nov 04 06:37:19 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:19 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:19 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:19 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 04 06:37:19 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:19 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:19 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:19 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:19 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:20 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:20 localhost volumio[21196]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"(DSD256)k4","artist":null,"album":null,"uri":"http://192.168.57.108:52100/Music/F940.dff","trackType":"dff"} Nov 04 06:37:20 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:20 localhost volumio[21196]: error: ControllerMpd::pushError: TypeError: Cannot read property 'indexOf' of null Nov 04 06:37:20 localhost volumio[21196]: info: ------------------------------ 40ms Nov 04 06:37:20 localhost volumio[21196]: info: Nov 04 06:37:20 localhost volumio[21196]: ---------------------------- Client requests Start RoonReady PlaybackRoutine Nov 04 06:37:20 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: roon_ready , startRoonReadyPlayback Nov 04 06:37:20 localhost volumio[21196]: info: Roon Ready playback start Nov 04 06:37:20 localhost volumio[21196]: info: CoreCommandRouter::volumioStop Nov 04 06:37:20 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:20 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:20 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:20 localhost volumio[21196]: info: Roon Ready metadata receiver is on Nov 04 06:37:20 localhost sudo[26748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart ifi-streamer-tidal-connect.service Nov 04 06:37:20 localhost sudo[26748]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:20 localhost node[422]: Closing connection with the client tidal-connect Nov 04 06:37:20 localhost systemd[1]: Stopping iFi Streamer Tidal Metadata Service... Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-metadata.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-metadata.service: Succeeded. Nov 04 06:37:20 localhost systemd[1]: Stopped iFi Streamer Tidal Metadata Service. Nov 04 06:37:20 localhost systemd[1]: Stopping iFi Streamer Tidal Connect Service... Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-connect.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:20 localhost node[466]: ConvSwitch: Drop client tidal Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-connect.service: Succeeded. Nov 04 06:37:20 localhost systemd[1]: Stopped iFi Streamer Tidal Connect Service. Nov 04 06:37:20 localhost systemd[1]: Started iFi Streamer Tidal Connect Service. Nov 04 06:37:20 localhost sudo[26748]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:20 localhost volumio[21196]: info: Tidal Connect Service Started Nov 04 06:37:20 localhost systemd[1]: Started iFi Streamer Tidal Metadata Service. Nov 04 06:37:20 localhost node[422]: A new connection has been established. Nov 04 06:37:20 localhost node[422]: metadata_handler Nov 04 06:37:20 localhost sudo[26753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart ifi-streamer-tidal-connect.service Nov 04 06:37:20 localhost sudo[26753]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:20 localhost sudo[26761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start ifi-streamer-qobuz-connect.service Nov 04 06:37:20 localhost systemd[1]: Stopping iFi Streamer Tidal Metadata Service... Nov 04 06:37:20 localhost node[422]: Closing connection with the client tidal-connect Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-metadata.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-metadata.service: Succeeded. Nov 04 06:37:20 localhost sudo[26761]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:20 localhost systemd[1]: Stopped iFi Streamer Tidal Metadata Service. Nov 04 06:37:20 localhost systemd[1]: Stopping iFi Streamer Tidal Connect Service... Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-connect.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:20 localhost systemd[1]: ifi-streamer-tidal-connect.service: Succeeded. Nov 04 06:37:20 localhost systemd[1]: Stopped iFi Streamer Tidal Connect Service. Nov 04 06:37:20 localhost systemd[1]: Started iFi Streamer Tidal Connect Service. Nov 04 06:37:20 localhost sudo[26753]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:20 localhost volumio[21196]: info: Tidal Connect Service Started Nov 04 06:37:20 localhost systemd[1]: Started iFi Streamer Tidal Metadata Service. Nov 04 06:37:20 localhost node[422]: A new connection has been established. Nov 04 06:37:20 localhost node[422]: metadata_handler Nov 04 06:37:20 localhost systemd[1]: Started iFi Streamer Qobuz Connect Service. Nov 04 06:37:20 localhost sudo[26761]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:20 localhost volumio[21196]: info: Qobuz Connect Service Started Nov 04 06:37:20 localhost sudo[26772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start ifi-streamer-qobuz-connect.service Nov 04 06:37:20 localhost sudo[26772]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:20 localhost sudo[26772]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:20 localhost volumio[21196]: info: Qobuz Connect Service Started Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Starting sample application Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Device Name: ZEN Stream Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Manufacturer: Sample manufacturer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Model: iFi Streamer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Serial Number: ifi:fa:88:b7:9a:1a:cf Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Audio output device: volumio Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Volume control device: default Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Volume control element: Master Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.826 [26797.26797] DEBUG SampleApp: Local config server port: 8000 Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.831 [26797.26797] ERROR SampleApp: Unable to find ALSA mixer element 'Master' on index 0 Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.831 [26797.26797] DEBUG SampleApp: Maximum supported audio quality: HIRES_L3 Nov 04 06:37:20 localhost play[26769]: [Info] MetaClient: MetaClient SDK -- v1.02 Nov 04 06:37:20 localhost node[422]: A new connection has been established. Nov 04 06:37:20 localhost node[422]: metadata_handler Nov 04 06:37:20 localhost play[26769]: [Info] MetaClient: MetaClientInit Nov 04 06:37:20 localhost play[26769]: [Info] ConvSwitch: ConvSwitch SDK -- v1.03 Nov 04 06:37:20 localhost node[466]: ConvSwitch: Add client qobuz-connect Nov 04 06:37:20 localhost play[26769]: [Info] ConvSwitch: ConvSwitchInit Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG ActiveStateManager: [0xaaf7ef40]: Creating new Active State Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG NetworkActivityTracker: [0xaaf7efb0]: Creating new Network Activity Tracker Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG EndpointManager: [0xaaf7ff28]: Creating Endpoint Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG PlaybackSessionManager: [0xaaf80318]: Creating Playback Session Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG BackoffTimer: [0xaaf80490]: Creating Backoff Timer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG MediaEngine: [0xaaf805b0]: Creating new Media Engine Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG AudioRenderer: [0xaaf807d0]: Creating Audio Renderer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] TRACE MediaEngineCommandSequencer: [0xaaf80928]: Creating Media Engine Command Sequencer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.938 [26797.26797] DEBUG PlaybackControlsManager: [0xaaf80988]: Creating new Playback Controls Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG VolumeManager: [0xaaf80a18]: Creating new Volume Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG ProtocolHandler: [0xaaf80cf0]: Creating Protocol Handler Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG MessageReceiver: [0xaaf80d90]: Creating Message Receiver Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG RendererActivationController: [0xaaf80f08]: Creating new Renderer Activation Controller Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] TRACE RendererActivationCommandSequencer: [0xaaf80fb0]: Creating Renderer Activation Command Sequencer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG ReportingManager: [0xaaf810c0]: Creating new Reporting Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG StreamingEventReporter: [0xaaf81108]: Creating Streaming Event Reporter Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG BackoffTimer: [0xaaf811e8]: Creating Backoff Timer Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG TokenExpiryController: [0xaaf812f8]: Creating Token Expiry Controller Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG UserInactivityManager: [0xaaf81348]: Creating new User Inactivity Manager Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] INFO VolumeManager: [0xaaf80a18]: Setting new playback volume: 100 Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] INFO VolumeManager: [0xaaf80a18]: Setting new mute state: 1 Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] DEBUG SampleApp: Qobuz Connect has been initialized Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] TRACE SampleApp: Running event loop Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] INFO QobuzConnect: [0xaaf813e8]: Client initialized! Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.939 [26797.26797] INFO SampleApp: Starting Avahi advertising, name: ZEN Stream, service name: _qobuz-connect._tcp Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.951 [26797.26797] DEBUG SampleApp: Avahi client state changed: RUNNING Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.956 [26797.26797] DEBUG SampleApp: Avahi entry group state changed: UNCOMMITED Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.968 [26797.26797] INFO LocalConfigManager: [0xaaf802f8]: Starting Local Configuration server Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.968 [26797.26797] INFO SampleApp: Starting Local configuration server Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.968 [26797.26797] INFO SampleApp: Playback mute state changed: 1 Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.969 [26797.26797] ERROR SampleApp: Unable to set mute state, no ALSA volume element Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.969 [26797.26797] DEBUG SampleApp: Avahi entry group state changed: REGISTERING Nov 04 06:37:20 localhost sudo[26801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop mpd.socket mpd.service Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.976 [26797.26797] INFO SampleApp: Playback volume changed: 100 Nov 04 06:37:20 localhost play[26769]: 20251104 06:37:20.976 [26797.26797] ERROR SampleApp: Unable to set volume, no ALSA volume element Nov 04 06:37:20 localhost sudo[26801]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:20 localhost systemd[1]: mpd.socket: Succeeded. Nov 04 06:37:20 localhost systemd[1]: Closed mpd.socket. Nov 04 06:37:20 localhost systemd[1]: Stopping Music Player Daemon... Nov 04 06:37:20 localhost volumio[21196]: MPD server connection closed Nov 04 06:37:21 localhost volumio[21196]: MPD server connection closed Nov 04 06:37:21 localhost sudo[26806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop mpd.socket mpd.service Nov 04 06:37:21 localhost sudo[26806]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:21 localhost systemd[1]: mpd.service: Succeeded. Nov 04 06:37:21 localhost systemd[1]: Stopped Music Player Daemon. Nov 04 06:37:21 localhost volumio[21196]: error: Service socket error: Error: This socket has been ended by the other party Nov 04 06:37:21 localhost sudo[26801]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:21 localhost sudo[26806]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:21 localhost sudo[26809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.socket mpd.service Nov 04 06:37:21 localhost sudo[26809]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:21 localhost sudo[26811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.socket mpd.service Nov 04 06:37:21 localhost sudo[26811]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:21 localhost systemd[1]: Listening on mpd.socket. Nov 04 06:37:21 localhost systemd[1]: mpd.socket: Succeeded. Nov 04 06:37:21 localhost systemd[1]: Closed mpd.socket. Nov 04 06:37:21 localhost systemd[1]: Stopping mpd.socket. Nov 04 06:37:21 localhost systemd[1]: Listening on mpd.socket. Nov 04 06:37:21 localhost systemd[1]: Starting Music Player Daemon... Nov 04 06:37:21 localhost systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 04 06:37:21 localhost systemd[1]: mpd.service: Succeeded. Nov 04 06:37:21 localhost systemd[1]: Stopped Music Player Daemon. Nov 04 06:37:21 localhost systemd[1]: Starting Music Player Daemon... Nov 04 06:37:21 localhost sudo[26815]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 04 06:37:21 localhost sudo[26815]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:21 localhost sudo[26815]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:21 localhost node[422]: A new connection has been established. Nov 04 06:37:21 localhost node[422]: metadata_handler Nov 04 06:37:21 localhost play[26769]: 20251104 06:37:21.834 [26797.26797] DEBUG SampleApp: Avahi entry group state changed: ESTABLISHED Nov 04 06:37:22 localhost sudo[26823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart ifi-streamer-spotify-connect.service Nov 04 06:37:22 localhost sudo[26823]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:22 localhost play[21739]: 2025-11-04 06:37:22.531 E esdk select error: 4 -> Interrupted system call Nov 04 06:37:22 localhost play[21739]: 2025-11-04 06:37:22.533 I app Exiting with error = 0 Nov 04 06:37:22 localhost play[21739]: 2025-11-04 06:37:22.533 I api SpFree() Nov 04 06:37:22 localhost play[21739]: 2025-11-04 06:37:22.533 I api SpFree [returned value: 0] Nov 04 06:37:22 localhost play[21739]: [Info] ConvSwitch: ConvSwitch SDK -- v1.03 Nov 04 06:37:22 localhost play[21739]: [Info] ConvSwitch: ConvSwitchInit Nov 04 06:37:22 localhost play[21739]: [Info] MetaClient: MetaClient SDK -- v1.02 Nov 04 06:37:22 localhost play[21739]: [Info] MetaClient: MetaClientInit Nov 04 06:37:22 localhost play[21739]: [Info] ConvSwitch: ConvSwitchExit Nov 04 06:37:22 localhost play[21739]: [Info] MetaClient: MetaClientExit Nov 04 06:37:22 localhost node[466]: ConvSwitch: Drop client spotify Nov 04 06:37:22 localhost node[422]: Closing connection with the client spotify Nov 04 06:37:22 localhost volumio[21196]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Nov 04 06:37:22 localhost volumio[21196]: info: CoreStateMachine::getcurrentVolume Nov 04 06:37:22 localhost volumio[21196]: info: CoreCommandRouter::volumioRetrievevolume Nov 04 06:37:22 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Nov 04 06:37:22 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:22 localhost systemd[1]: Stopping iFi Streamer Spotify Connect Service... Nov 04 06:37:22 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:22 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:22 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:22 localhost systemd[1]: ifi-streamer-spotify-connect.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:22 localhost systemd[1]: ifi-streamer-spotify-connect.service: Succeeded. Nov 04 06:37:22 localhost systemd[1]: Stopped iFi Streamer Spotify Connect Service. Nov 04 06:37:22 localhost systemd[1]: Started iFi Streamer Spotify Connect Service. Nov 04 06:37:22 localhost sudo[26823]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:22 localhost volumio[21196]: info: Spotify Connect Service Started Nov 04 06:37:22 localhost sudo[26826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart ifi-streamer-spotify-connect.service Nov 04 06:37:22 localhost sudo[26826]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 04 06:37:22 localhost systemd[1]: Stopping iFi Streamer Spotify Connect Service... Nov 04 06:37:22 localhost systemd[1]: ifi-streamer-spotify-connect.service: Main process exited, code=killed, status=15/TERM Nov 04 06:37:22 localhost systemd[1]: ifi-streamer-spotify-connect.service: Succeeded. Nov 04 06:37:22 localhost systemd[1]: Stopped iFi Streamer Spotify Connect Service. Nov 04 06:37:22 localhost systemd[1]: Started iFi Streamer Spotify Connect Service. Nov 04 06:37:22 localhost sudo[26826]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:22 localhost volumio[21196]: info: Spotify Connect Service Started Nov 04 06:37:22 localhost play[26846]: output: volumio mixer: hw:0 Nov 04 06:37:22 localhost node[466]: ConvSwitch: Add client spotify Nov 04 06:37:22 localhost node[422]: A new connection has been established. Nov 04 06:37:22 localhost node[422]: metadata_handler Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.984 I api SpRegisterDebugCallbacks [returned value: 0] Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.984 I api SpInit(0xffef46e0, API v66) Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.984 I esdk eSDK version: HEAD-v3.166.69-g24821f73 Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.985 I esdk Successfully registered socket callbacks: cre, set_opt, cl, bind, list, con, acc, rd, wr, rd_from, wr_to, err, readable, writable, local_addresses, address, pump Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.985 I esdk Successfully registered dns callback: dns_lookup_callback Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.985 I download Using 128 kB for cache buffer Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.985 I download Using 621 kB for compressed audio buffer Nov 04 06:37:22 localhost play[26846]: 2025-11-04 06:37:22.985 I esdk Successfully registered error callback Nov 04 06:37:23 localhost volumio[21196]: info: VolumeController::SetAlsaVolume100 Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.002 I esdk Creating IPv4 socket (domain 2) Nov 04 06:37:23 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Nov 04 06:37:23 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.004 I zc webserver: service port 5566 (5566-5576) buffer size 4444 Nov 04 06:37:23 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:23 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.006 I zc Started ZeroConf service on port 5566 path /zc alias count 0 Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.008 I esdk Creating IPv4 socket (domain 2) Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.010 I api SpInit [returned value: 0] Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.011 I api SpRegisterConnectionCallbacks(0xffef46c8, (nil)) Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.012 I esdk Successfully registered connection callbacks: on_notify, on_message, on_new_credentials Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.013 I api SpRegisterConnectionCallbacks [returned value: 0] Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.013 I api SpRegisterPlaybackCallbacks(0xffef46b0, (nil)) Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.014 I esdk Successfully registered playback callbacks: on_notify, on_audio_data, on_seek, on_apply_volume, - Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.015 I api SpRegisterPlaybackCallbacks [returned value: 0] Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.022 W app Couldn't find mixer for volume controls. (tried , SoftMaster) Nov 04 06:37:23 localhost play[26846]: 2025-11-04 06:37:23.023 I app Initialized! Nov 04 06:37:23 localhost node[466]: ConvSwitch: Add client tidal Nov 04 06:37:23 localhost tidal_connect_application[26871]: *** WARNING *** The program 'tidal_connect_application' uses the Apple Bonjour compatibility layer of Avahi. Nov 04 06:37:23 localhost tidal_connect_application[26871]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 04 06:37:23 localhost tidal_connect_application[26871]: *** WARNING *** For more information see Nov 04 06:37:23 localhost ifi_metadata[26764]: [Info] MetaClient: MetaClient SDK -- v1.02 Nov 04 06:37:23 localhost ifi_metadata[26764]: [Info] MetaClient: MetaClientInit Nov 04 06:37:23 localhost ifi_metadata[26764]: Connected Nov 04 06:37:24 localhost mpd[26817]: Nov 04 06:37 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 04 06:37:24 localhost systemd[1]: Started Music Player Daemon. Nov 04 06:37:24 localhost sudo[26809]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:24 localhost volumio[21196]: info: Restarted MPD. Nov 04 06:37:24 localhost sudo[26811]: pam_unix(sudo:session): session closed for user root Nov 04 06:37:24 localhost systemd[1]: Starting Internet Detect for iFi Streamer... Nov 04 06:37:24 localhost volumio[21196]: error: MPD error: The expression evaluated to a falsy value: Nov 04 06:37:24 localhost volumio[21196]: assert.ok(self.idling) Nov 04 06:37:24 localhost volumio[21196]: error: The expression evaluated to a falsy value: Nov 04 06:37:24 localhost volumio[21196]: assert.ok(self.idling) Nov 04 06:37:24 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:37:24 localhost systemd[1]: ifi-system-internet.service: Succeeded. Nov 04 06:37:24 localhost systemd[1]: Started Internet Detect for iFi Streamer. Nov 04 06:37:24 localhost volumio[21196]: info: CoreCommandRouter::volumioStop Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::serviceStop Nov 04 06:37:24 localhost volumio[21196]: info: CoreCommandRouter::serviceStop Nov 04 06:37:24 localhost volumio[21196]: info: CoreCommandRouter::volumioStop Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:24 localhost volumio[21196]: info: Roon Ready Stop Nov 04 06:37:24 localhost volumio[21196]: info: CoreCommandRouter::volumioStop Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:24 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:34 localhost volumio[21196]: info: Clearing queue after UPNP request Nov 04 06:37:34 localhost volumio[21196]: Connection closed by client Nov 04 06:37:34 localhost volumio[21196]: New connection from ::ffff:127.0.0.1:46248 Nov 04 06:37:34 localhost volumio[21196]: Connected to MPD server Nov 04 06:37:34 localhost volumio[21196]: info: Clearing queue after UPNP request Nov 04 06:37:34 localhost volumio[21196]: New connection from ::ffff:127.0.0.1:46252 Nov 04 06:37:34 localhost volumio[21196]: Connected to MPD server Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::ClearQueue Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:34 localhost volumio[21196]: info: CorePlayQueue::clearPlayQueue Nov 04 06:37:34 localhost volumio[21196]: info: CorePlayQueue::saveQueue Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::volumioPushQueue Nov 04 06:37:34 localhost volumio[21196]: error: Service socket error: Error: This socket has been ended by the other party Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::ClearQueue Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::stop Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 06:37:34 localhost volumio[21196]: info: CorePlayQueue::clearPlayQueue Nov 04 06:37:34 localhost volumio[21196]: info: CorePlayQueue::saveQueue Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::volumioPushQueue Nov 04 06:37:34 localhost volumio[21196]: info: Nov 04 06:37:34 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:34 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:34 localhost volumio[21196]: info: Nov 04 06:37:34 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:34 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:34 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:37:34 localhost volumio[21196]: error: updateQueue error: null Nov 04 06:37:34 localhost volumio[21196]: info: ------------------------------ 14ms Nov 04 06:37:34 localhost volumio[21196]: info: ------------------------------ 13ms Nov 04 06:37:34 localhost volumio[21196]: info: Starting UPNP Playback Nov 04 06:37:34 localhost volumio[21196]: info: ConvSwitch: Sent Play Nov 04 06:37:34 localhost volumio[21196]: info: Preparing playback through UPNP Nov 04 06:37:34 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:34 localhost volumio[21196]: info: CorePlayQueue::getTrack 0 Nov 04 06:37:34 localhost volumio[21196]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 04 06:37:34 localhost volumio[21196]: info: ConvSwitch: Get message: success Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 9ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 7ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 8ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 5ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 8ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 10ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 7ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 11ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 7ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 7ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 4ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:35 localhost kernel: wm8804 0-003b: wm8804_hw_params rate: 0xac44 format: 0x2 Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand status took 27 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand status took 19 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand status took 44 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 56ms Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand status took 41 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 39 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 33 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand status took 15 milliseconds Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:35 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:37:35 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":196,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Carmen 44kHz","artist":"Carmen","album":"RMAF 2010","uri":"http://192.168.57.108:52100/Music/F959.flac","trackType":"flac"} Nov 04 06:37:35 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus stop Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:35 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:37:35 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":196,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Carmen 44kHz","artist":"Carmen","album":"RMAF 2010","uri":"http://192.168.57.108:52100/Music/F959.flac","trackType":"flac"} Nov 04 06:37:35 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:37:35 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 218ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 229ms Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces system playlist update Nov 04 06:37:35 localhost volumio[21196]: info: Ignoring MPD Status Update Nov 04 06:37:35 localhost volumio[21196]: info: Nov 04 06:37:35 localhost volumio[21196]: ---------------------------- MPD announces state update: player Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::getState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand status Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 161 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 157 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand playlistinfo took 150 milliseconds Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 27ms Nov 04 06:37:35 localhost volumio[21196]: info: sendMpdCommand status took 14 milliseconds Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseTrackInfo Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::parseState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetState Nov 04 06:37:35 localhost volumio[21196]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:35 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:37:35 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":755,"duration":196,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"Carmen 44kHz","artist":"Carmen","album":"RMAF 2010","uri":"http://192.168.57.108:52100/Music/F959.flac","trackType":"flac"} Nov 04 06:37:35 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:37:35 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:35 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:37:35 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":755,"duration":196,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"696 Kbps","isStreaming":false,"title":"Carmen 44kHz","artist":"Carmen","album":"RMAF 2010","uri":"http://192.168.57.108:52100/Music/F959.flac","trackType":"flac"} Nov 04 06:37:35 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:37:35 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: ControllerMpd::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::servicePushState Nov 04 06:37:35 localhost volumio[21196]: verbose: In UPNP mode Nov 04 06:37:35 localhost volumio[21196]: verbose: STATE SERVICE {"status":"play","position":0,"seek":755,"duration":196,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"696 Kbps","isStreaming":false,"title":"Carmen 44kHz","artist":"Carmen","album":"RMAF 2010","uri":"http://192.168.57.108:52100/Music/F959.flac","trackType":"flac"} Nov 04 06:37:35 localhost volumio[21196]: verbose: CURRENT POSITION 0 Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState stateService play Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::syncState currentStatus play Nov 04 06:37:35 localhost volumio[21196]: info: Received an update from plugin. extracting info from payload Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::pushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioPushState Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 405ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 403ms Nov 04 06:37:35 localhost volumio[21196]: info: ------------------------------ 365ms Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:35 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:35 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:35 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:35 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:35 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreCommandRouter::volumioGetQueue Nov 04 06:37:36 localhost volumio[21196]: info: CoreStateMachine::getQueue Nov 04 06:37:36 localhost volumio[21196]: info: CorePlayQueue::getQueue Nov 04 06:37:36 localhost volumio[21196]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 06:37:36 localhost volumio[21196]: TypeError: Cannot read property 'logger' of undefined Nov 04 06:37:36 localhost volumio[21196]: at /volumio/app/statemachine.js:629:16 Nov 04 06:37:36 localhost volumio[21196]: at ChildProcess.exithandler (child_process.js:390:5) Nov 04 06:37:36 localhost volumio[21196]: at ChildProcess.emit (events.js:400:28) Nov 04 06:37:36 localhost volumio[21196]: at maybeClose (internal/child_process.js:1088:16) Nov 04 06:37:36 localhost volumio[21196]: at Socket. (internal/child_process.js:446:11) Nov 04 06:37:36 localhost volumio[21196]: at Socket.emit (events.js:400:28) Nov 04 06:37:36 localhost volumio[21196]: at Pipe. (net.js:686:12) Nov 04 06:37:36 localhost volumio[21196]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 06:37:37 localhost sudo[27026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-04 06:36 Nov 04 06:37:37 localhost sudo[27026]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b6b5fc9c726190e478d1307bf4816c8d6dfb5af2" VOLUMIO_FE_VERSION="607f0b2839009ad71a89496f82d0c60770a281b7" VOLUMIO_FE3_VERSION="c98f50471352dc221c4a2aa0af52effb0ef3ca54" VOLUMIO_BE_VERSION="a0b0b71b1190468adb5bea37ae28ea417ba4e5f1" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="ifi" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Oct 31 19:06:26 CST 2025" VOLUMIO_VERSION="3.00.3" VOLUMIO_HARDWARE="zen-stream" VOLUMIO_DEVICENAME="ZEN Stream" VOLUMIO_HASH="3bbd4a158ba48434722867160220a086"