-- Logs begin at Mon 2025-07-07 05:47:24 CEST, end at Fri 2025-07-11 23:01:55 CEST. -- Jul 11 23:00:02 volumio kernel: CIFS: Attempting to mount //192.168.1.125/C/Users/AD/AppData/Local/Temporary Internet Files Jul 11 23:00:02 volumio kernel: CIFS: VFS: Autodisabling the use of server inode numbers on \\192.168.1.125\C Jul 11 23:00:02 volumio kernel: CIFS: VFS: The server doesn't seem to support them properly or the files might be on different servers (DFS) Jul 11 23:00:02 volumio kernel: CIFS: VFS: Hardlinks will not be recognized on this mount. Consider mounting with the "noserverino" option to silence this message. Jul 11 23:00:04 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jul 11 23:00:04 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:06 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jul 11 23:00:06 volumio volumio[1136]: info: Getting BBC Radios Jul 11 23:00:07 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:08 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:08 volumio volumio[1136]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::ClearQueue Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::clearPlayQueue Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:00:08 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:00:08 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:08 volumio volumio[1136]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Jul 11 23:00:08 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jul 11 23:00:08 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:00:08 volumio volumio[1136]: info: CoreCommandRouter::volumioPlay Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::play index 0 Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::play index undefined Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::startPlaybackTimer Jul 11 23:00:08 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:08 volumio volumio[1136]: info: [1752267608844] ControllerWebradio::clearAddPlayTrack Jul 11 23:00:08 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:00:08 volumio volumio[1136]: info: sendMpdCommand stop took 1 milliseconds Jul 11 23:00:08 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand clear Jul 11 23:00:08 volumio volumio[1136]: info: Jul 11 23:00:08 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:00:08 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:00:08 volumio volumio[1136]: info: sendMpdCommand clear took 0 milliseconds Jul 11 23:00:08 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand add "http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8" Jul 11 23:00:08 volumio volumio[1136]: error: updateQueue error: null Jul 11 23:00:08 volumio volumio[1136]: info: Jul 11 23:00:08 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:00:08 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:00:08 volumio volumio[1136]: info: ------------------------------ 2ms Jul 11 23:00:08 volumio volumio[1136]: info: sendMpdCommand add "http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8" took 1 milliseconds Jul 11 23:00:08 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 11 23:00:08 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand play Jul 11 23:00:08 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:00:08 volumio volumio[1136]: info: sendMpdCommand play took 1 milliseconds Jul 11 23:00:10 volumio volumio[1136]: info: Jul 11 23:00:10 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:00:10 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:00:10 volumio volumio[1136]: info: Jul 11 23:00:10 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:00:10 volumio volumio[1136]: info: sendMpdCommand status took 14 milliseconds Jul 11 23:00:10 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:00:10 volumio volumio[1136]: info: sendMpdCommand status took 1 milliseconds Jul 11 23:00:10 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:00:10 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:00:10 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:00:10 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:10 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_one.m3u8","artist":null,"album":null,"uri":"http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8","trackType":"m3u8"} Jul 11 23:00:10 volumio volumio[1136]: verbose: CURRENT POSITION 0 Jul 11 23:00:10 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:00:10 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus stop Jul 11 23:00:10 volumio volumio[1136]: info: ------------------------------ 16ms Jul 11 23:00:10 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 11 23:00:10 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:00:10 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:00:10 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:00:10 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:10 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_one.m3u8","artist":null,"album":null,"uri":"http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8","trackType":"m3u8"} Jul 11 23:00:10 volumio volumio[1136]: verbose: CURRENT POSITION 0 Jul 11 23:00:10 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:00:10 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus play Jul 11 23:00:10 volumio volumio[1136]: info: Received an update from plugin. extracting info from payload Jul 11 23:00:10 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:00:10 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:10 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:00:10 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:00:10 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:00:10 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:00:10 volumio volumio[1136]: info: ------------------------------ 7ms Jul 11 23:00:14 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::ClearQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::stPlaybackTimer Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::serviceStop Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::serviceStop Jul 11 23:00:14 volumio volumio[1136]: info: [1752267614064] ControllerWebradio::stop Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::clearPlayQueue Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:00:14 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:14 volumio volumio[1136]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPlay Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::play index 0 Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::play index undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::startPlaybackTimer Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:14 volumio volumio[1136]: info: [1752267614069] ControllerWebradio::clearAddPlayTrack Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:00:14 volumio volumio[1136]: info: Jul 11 23:00:14 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:00:14 volumio volumio[1136]: info: sendMpdCommand stop took 6 milliseconds Jul 11 23:00:14 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:00:14 volumio volumio[1136]: info: sendMpdCommand stop took 2 milliseconds Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand clear Jul 11 23:00:14 volumio volumio[1136]: info: Jul 11 23:00:14 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:00:14 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:00:14 volumio volumio[1136]: info: sendMpdCommand status took 0 milliseconds Jul 11 23:00:14 volumio volumio[1136]: info: sendMpdCommand clear took 0 milliseconds Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand load "https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio" Jul 11 23:00:14 volumio volumio[1136]: error: updateQueue error: null Jul 11 23:00:14 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:00:14 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:00:14 volumio volumio[1136]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 11 23:00:14 volumio volumio[1136]: info: ------------------------------ 3ms Jul 11 23:00:14 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::ClearQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::clearPlayQueue Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:00:14 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:14 volumio volumio[1136]: info: Adding Item to queue: https://d2vnbkvjbims7j.cloudfront.net/containerA/LTN/playlist.m3u8 Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:00:14 volumio volumio[1136]: info: CoreCommandRouter::volumioPlay Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::play index 0 Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::play index undefined Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:14 volumio volumio[1136]: info: CoreStateMachine::startPlaybackTimer Jul 11 23:00:14 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:14 volumio volumio[1136]: info: [1752267614865] ControllerWebradio::clearAddPlayTrack Jul 11 23:00:14 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:00:15 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand add "https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio" Jul 11 23:00:15 volumio volumio[1136]: info: sendMpdCommand stop took 761 milliseconds Jul 11 23:00:15 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand clear Jul 11 23:00:15 volumio volumio[1136]: info: Jul 11 23:00:15 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:00:15 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:00:15 volumio volumio[1136]: info: Jul 11 23:00:15 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:00:15 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:00:15 volumio volumio[1136]: info: sendMpdCommand add "https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio" took 2 milliseconds Jul 11 23:00:15 volumio volumio[1136]: info: sendMpdCommand clear took 1 milliseconds Jul 11 23:00:15 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 11 23:00:15 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand play Jul 11 23:00:15 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand add "https://d2vnbkvjbims7j.cloudfront.net/containerA/LTN/playlist.m3u8" Jul 11 23:00:15 volumio volumio[1136]: error: updateQueue error: null Jul 11 23:00:15 volumio volumio[1136]: error: updateQueue error: null Jul 11 23:00:15 volumio volumio[1136]: info: Jul 11 23:00:15 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:00:15 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:00:15 volumio volumio[1136]: info: ------------------------------ 2ms Jul 11 23:00:15 volumio volumio[1136]: info: ------------------------------ 2ms Jul 11 23:00:15 volumio volumio[1136]: info: sendMpdCommand play took 1 milliseconds Jul 11 23:00:15 volumio volumio[1136]: info: sendMpdCommand add "https://d2vnbkvjbims7j.cloudfront.net/containerA/LTN/playlist.m3u8" took 1 milliseconds Jul 11 23:00:15 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 11 23:00:15 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand play Jul 11 23:00:15 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:00:15 volumio volumio[1136]: info: sendMpdCommand play took 1 milliseconds Jul 11 23:00:18 volumio volumio[1136]: info: CoreCommandRouter::volumioGetState Jul 11 23:00:20 volumio volumio[1136]: info: Jul 11 23:00:20 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:00:20 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:00:20 volumio volumio[1136]: info: Jul 11 23:00:20 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:00:20 volumio volumio[1136]: info: sendMpdCommand status took 3 milliseconds Jul 11 23:00:20 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:00:20 volumio volumio[1136]: info: sendMpdCommand status took 0 milliseconds Jul 11 23:00:20 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:00:20 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:00:20 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:00:20 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:20 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://d2vnbkvjbims7j.cloudfront.net/containerA/LTN/playlist.m3u8","trackType":"m3u8"} Jul 11 23:00:20 volumio volumio[1136]: verbose: CURRENT POSITION 0 Jul 11 23:00:20 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:00:20 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus stop Jul 11 23:00:20 volumio volumio[1136]: info: ------------------------------ 6ms Jul 11 23:00:20 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 11 23:00:20 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:00:20 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:00:20 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:00:20 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:20 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://d2vnbkvjbims7j.cloudfront.net/containerA/LTN/playlist.m3u8","trackType":"m3u8"} Jul 11 23:00:20 volumio volumio[1136]: verbose: CURRENT POSITION 0 Jul 11 23:00:20 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:00:20 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus play Jul 11 23:00:20 volumio volumio[1136]: info: Received an update from plugin. extracting info from payload Jul 11 23:00:20 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:00:20 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:00:20 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:00:20 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:00:20 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:00:20 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:00:20 volumio volumio[1136]: info: ------------------------------ 10ms Jul 11 23:00:22 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:22 volumio volumio[1136]: info: CURURI: music-library Jul 11 23:00:22 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:23 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:23 volumio volumio[1136]: info: CURURI: music-library/NAS Jul 11 23:00:24 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:25 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:25 volumio volumio[1136]: info: CURURI: music-library/NAS/Win11 Jul 11 23:00:25 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:27 volumio volumio[1136]: An internal error occurred while serving an albumart. Details: Error: EACCES: permission denied, scandir '/mnt/NAS/Win11/PerfLogs' Jul 11 23:00:27 volumio volumio[1136]: at Object.readdirSync (fs.js:1048:3) Jul 11 23:00:27 volumio volumio[1136]: at searchInFolder (/volumio/app/plugins/miscellanea/albumart/albumart.js:250:20) Jul 11 23:00:27 volumio volumio[1136]: at processRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:386:11) Jul 11 23:00:27 volumio volumio[1136]: at processExpressRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:437:17) Jul 11 23:00:27 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:27 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) Jul 11 23:00:27 volumio volumio[1136]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) Jul 11 23:00:27 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:27 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:281:22 Jul 11 23:00:27 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:27 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Jul 11 23:00:27 volumio volumio[1136]: at allowCrossDomain (/volumio/http/index.js:34:5) Jul 11 23:00:27 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:27 volumio volumio[1136]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Jul 11 23:00:27 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:284:7 Jul 11 23:00:27 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:28 volumio volumio[1136]: An internal error occurred while serving an albumart. Details: Error: EACCES: permission denied, scandir '/mnt/NAS/Win11/Recovery' Jul 11 23:00:28 volumio volumio[1136]: at Object.readdirSync (fs.js:1048:3) Jul 11 23:00:28 volumio volumio[1136]: at searchInFolder (/volumio/app/plugins/miscellanea/albumart/albumart.js:250:20) Jul 11 23:00:28 volumio volumio[1136]: at processRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:386:11) Jul 11 23:00:28 volumio volumio[1136]: at processExpressRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:437:17) Jul 11 23:00:28 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:28 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) Jul 11 23:00:28 volumio volumio[1136]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) Jul 11 23:00:28 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:28 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:281:22 Jul 11 23:00:28 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:28 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Jul 11 23:00:28 volumio volumio[1136]: at allowCrossDomain (/volumio/http/index.js:34:5) Jul 11 23:00:28 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:28 volumio volumio[1136]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Jul 11 23:00:28 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:284:7 Jul 11 23:00:28 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:28 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:28 volumio volumio[1136]: info: CURURI: music-library/NAS/Win11/Users Jul 11 23:00:28 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:29 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:29 volumio volumio[1136]: info: CURURI: music-library/NAS/Win11/Users/AD Jul 11 23:00:30 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:33 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:33 volumio volumio[1136]: info: CURURI: music-library Jul 11 23:00:33 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:34 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:34 volumio volumio[1136]: info: CURURI: music-library/INTERNAL Jul 11 23:00:34 volumio volumio[1136]: error: Failed LSINFO: null Jul 11 23:00:34 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:37 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:37 volumio volumio[1136]: info: CURURI: music-library/NAS Jul 11 23:00:37 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:38 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:38 volumio volumio[1136]: info: CURURI: music-library/NAS/Win11 Jul 11 23:00:38 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:39 volumio volumio[1136]: An internal error occurred while serving an albumart. Details: Error: EACCES: permission denied, scandir '/mnt/NAS/Win11/PerfLogs' Jul 11 23:00:39 volumio volumio[1136]: at Object.readdirSync (fs.js:1048:3) Jul 11 23:00:39 volumio volumio[1136]: at searchInFolder (/volumio/app/plugins/miscellanea/albumart/albumart.js:250:20) Jul 11 23:00:39 volumio volumio[1136]: at processRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:386:11) Jul 11 23:00:39 volumio volumio[1136]: at processExpressRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:437:17) Jul 11 23:00:39 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:39 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) Jul 11 23:00:39 volumio volumio[1136]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) Jul 11 23:00:39 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:39 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:281:22 Jul 11 23:00:39 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:39 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Jul 11 23:00:39 volumio volumio[1136]: at allowCrossDomain (/volumio/http/index.js:34:5) Jul 11 23:00:39 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:39 volumio volumio[1136]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Jul 11 23:00:39 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:284:7 Jul 11 23:00:39 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:40 volumio volumio[1136]: An internal error occurred while serving an albumart. Details: Error: EACCES: permission denied, scandir '/mnt/NAS/Win11/Recovery' Jul 11 23:00:40 volumio volumio[1136]: at Object.readdirSync (fs.js:1048:3) Jul 11 23:00:40 volumio volumio[1136]: at searchInFolder (/volumio/app/plugins/miscellanea/albumart/albumart.js:250:20) Jul 11 23:00:40 volumio volumio[1136]: at processRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:386:11) Jul 11 23:00:40 volumio volumio[1136]: at processExpressRequest (/volumio/app/plugins/miscellanea/albumart/albumart.js:437:17) Jul 11 23:00:40 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:40 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) Jul 11 23:00:40 volumio volumio[1136]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) Jul 11 23:00:40 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:40 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:281:22 Jul 11 23:00:40 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:40 volumio volumio[1136]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) Jul 11 23:00:40 volumio volumio[1136]: at allowCrossDomain (/volumio/http/index.js:34:5) Jul 11 23:00:40 volumio volumio[1136]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) Jul 11 23:00:40 volumio volumio[1136]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) Jul 11 23:00:40 volumio volumio[1136]: at /volumio/node_modules/express/lib/router/index.js:284:7 Jul 11 23:00:40 volumio volumio[1136]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) Jul 11 23:00:41 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jul 11 23:00:41 volumio volumio[1136]: info: CURURI: music-library/USB Jul 11 23:00:41 volumio volumio[1136]: error: Failed LSINFO: null Jul 11 23:00:41 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:46 volumio volumio[1136]: info: CoreCommandRouter::volumioGetState Jul 11 23:00:52 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:00:52 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:54 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:00:54 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:56 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:00:58 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:00:58 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:02 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:03 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:06 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:07 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:09 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:11 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:12 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:17 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:17 volumio volumio[1136]: error: Error browsing14_a98c9024_7c3c493f:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:17 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:20 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:20 volumio volumio[1136]: error: Error browsing14_a98c9024_bf7d3be:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:20 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:22 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:22 volumio volumio[1136]: error: Error browsing14_a98c9024_7c3c493f:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:22 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:23 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:23 volumio volumio[1136]: error: Error browsing14_a98c9024_7c3c493f:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:23 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:25 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:27 volumio volumio[1136]: error: Error browsing14_a98c9024_bf7d3be:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:27 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:27 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:28 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:28 volumio volumio[1136]: error: Error browsing14_a98c9024_bf7d3be:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:28 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:29 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23698 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23702 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23707 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23709 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23704 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23703 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23701 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23700 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23705 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23706 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23699 Jul 11 23:01:29 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23708 Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23698 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23702 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23707 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23709 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23704 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23703 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23701 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23700 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23705 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23706 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23699 in service upnp_browser Jul 11 23:01:29 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23708 in service upnp_browser Jul 11 23:01:31 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::ClearQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::stPlaybackTimer Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::serviceStop Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::serviceStop Jul 11 23:01:31 volumio volumio[1136]: info: [1752267691378] ControllerWebradio::stop Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::clearPlayQueue Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:01:31 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/folder/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc_2997b4a Jul 11 23:01:31 volumio volumio[1136]: info: Exploding uri upnp/folder/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc_2997b4a in service upnp_browser Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23698 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23698 Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand stop took 30 milliseconds Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand status took 1 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:01:31 volumio volumio[1136]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://d2vnbkvjbims7j.cloudfront.net/containerA/LTN/playlist.m3u8","trackType":"m3u8"} Jul 11 23:01:31 volumio volumio[1136]: verbose: CURRENT POSITION 0 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState stateService stop Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus stop Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: No code Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 0 Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 9ms Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPlay Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::play index 1 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:01:31 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23702 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23702 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23707 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23707 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23709 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23709 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23704 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23704 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23703 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23703 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23701 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23701 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23700 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23700 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23705 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23705 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23706 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23706 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23699 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23699 Jul 11 23:01:31 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23708 Jul 11 23:01:31 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_1fe422dc-23708 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::play index undefined Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::startPlaybackTimer Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:31 volumio volumio[1136]: info: [1752267691558] ControllerUPNPBrowser::clearAddPlayTrack Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand stop took 2 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand clear Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:01:31 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand clear took 1 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI" Jul 11 23:01:31 volumio volumio[1136]: error: updateQueue error: null Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 2ms Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI" Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:01:31 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand add "http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI" took 0 milliseconds Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand play Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand play took 1 milliseconds Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand status took 16 milliseconds Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand status took 0 milliseconds Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:31 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":225,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI","artist":null,"album":null,"uri":"http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI","trackType":""} Jul 11 23:01:31 volumio volumio[1136]: verbose: CURRENT POSITION 1 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus stop Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 17ms Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:31 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":225,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI","artist":null,"album":null,"uri":"http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI","trackType":""} Jul 11 23:01:31 volumio volumio[1136]: verbose: CURRENT POSITION 1 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus play Jul 11 23:01:31 volumio volumio[1136]: info: Received an update from plugin. extracting info from payload Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 6ms Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:01:31 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:01:31 volumio volumio[1136]: info: Jul 11 23:01:31 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand status took 1 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:31 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:01:31 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:31 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:31 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":225,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"615 Kbps","isStreaming":false,"title":"Jst ti dam","artist":"Muff","album":"Muff","uri":"http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfMWZlNDIyZGMtMjM3MDI","trackType":""} Jul 11 23:01:31 volumio volumio[1136]: verbose: CURRENT POSITION 1 Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus play Jul 11 23:01:31 volumio volumio[1136]: info: Received an update from plugin. extracting info from payload Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:31 volumio volumio[1136]: info: ------------------------------ 5ms Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioGetQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::getQueue Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreCommandRouter::volumioGetQueue Jul 11 23:01:31 volumio volumio[1136]: info: CoreStateMachine::getQueue Jul 11 23:01:31 volumio volumio[1136]: info: CorePlayQueue::getQueue Jul 11 23:01:36 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:37 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:37 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6633 Jul 11 23:01:37 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6634 Jul 11 23:01:37 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6630 Jul 11 23:01:37 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6631 Jul 11 23:01:37 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6629 Jul 11 23:01:37 volumio volumio[1136]: info: Preloading song: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6632 Jul 11 23:01:37 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6633 in service upnp_browser Jul 11 23:01:37 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6634 in service upnp_browser Jul 11 23:01:37 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6630 in service upnp_browser Jul 11 23:01:37 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6631 in service upnp_browser Jul 11 23:01:37 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6629 in service upnp_browser Jul 11 23:01:37 volumio volumio[1136]: info: Exploding uri upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6632 in service upnp_browser Jul 11 23:01:41 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::ClearQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::stPlaybackTimer Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::serviceStop Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 1 Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::serviceStop Jul 11 23:01:41 volumio volumio[1136]: info: [1752267701317] ControllerUPNPBrowser::stop Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::clearPlayQueue Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:01:41 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:41 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6633 Jul 11 23:01:41 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6633 Jul 11 23:01:41 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6634 Jul 11 23:01:41 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6634 Jul 11 23:01:41 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6630 Jul 11 23:01:41 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6630 Jul 11 23:01:41 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6631 Jul 11 23:01:41 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6631 Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPlay Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::play index 3 Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::addQueueItems Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::addQueueItems Jul 11 23:01:41 volumio volumio[1136]: info: Preload queue cleared Jul 11 23:01:41 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6629 Jul 11 23:01:41 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6629 Jul 11 23:01:41 volumio volumio[1136]: info: Adding Item to queue: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6632 Jul 11 23:01:41 volumio volumio[1136]: info: Using cached record of: upnp/http://192.168.1.125:2869/upnphost/udhisapi.dll?control=uuid:52c603ae-334a-44b2-a990-90e19a324bd8+urn:upnp-org:serviceId:ContentDirectory@14_a98c9024_414e6d1a-6632 Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::stop Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushQueue Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::saveQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::play index undefined Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::updateTrackBlock Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrackBlock Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 3 Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::startPlaybackTimer Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 3 Jul 11 23:01:41 volumio volumio[1136]: info: [1752267701323] ControllerUPNPBrowser::clearAddPlayTrack Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand stop Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand stop took 7 milliseconds Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand stop took 1 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand clear Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:01:41 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand status took 1 milliseconds Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand clear took 1 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ" Jul 11 23:01:41 volumio volumio[1136]: error: updateQueue error: null Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 0ms Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:41 volumio volumio[1136]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 2ms Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ" Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:01:41 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand add "http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ" took 0 milliseconds Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand play Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand play took 1 milliseconds Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand status took 2 milliseconds Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand status took 0 milliseconds Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 3 Jul 11 23:01:41 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ","artist":null,"album":null,"uri":"http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ","trackType":""} Jul 11 23:01:41 volumio volumio[1136]: verbose: CURRENT POSITION 3 Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus stop Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 3ms Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 3 Jul 11 23:01:41 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ","artist":null,"album":null,"uri":"http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ","trackType":""} Jul 11 23:01:41 volumio volumio[1136]: verbose: CURRENT POSITION 3 Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus play Jul 11 23:01:41 volumio volumio[1136]: info: Received an update from plugin. extracting info from payload Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 6ms Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces system playlist update Jul 11 23:01:41 volumio volumio[1136]: info: Ignoring MPD Status Update Jul 11 23:01:41 volumio volumio[1136]: info: Jul 11 23:01:41 volumio volumio[1136]: ---------------------------- MPD announces state update: player Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::getState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand status Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 1ms Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand status took 1 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseState Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 11 23:01:41 volumio volumio[1136]: info: sendMpdCommand playlistinfo took 0 milliseconds Jul 11 23:01:41 volumio volumio[1136]: verbose: ControllerMpd::parseTrackInfo Jul 11 23:01:41 volumio volumio[1136]: info: ControllerMpd::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::servicePushState Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getTrack 3 Jul 11 23:01:41 volumio volumio[1136]: verbose: STATE SERVICE {"status":"play","position":0,"seek":842,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Male roke (Live)","artist":"Siddharta","album":"Male roke","uri":"http://192.168.1.125:10243/WMPNSSv4/1526298740/0_MTRfYTk4YzkwMjRfNDE0ZTZkMWEtNjYzMQ","trackType":""} Jul 11 23:01:41 volumio volumio[1136]: verbose: CURRENT POSITION 3 Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::syncState stateService play Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::syncState currentStatus play Jul 11 23:01:41 volumio volumio[1136]: info: Received an update from plugin. extracting info from payload Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:41 volumio volumio[1136]: info: ------------------------------ 7ms Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioGetQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::getQueue Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreCommandRouter::volumioGetQueue Jul 11 23:01:41 volumio volumio[1136]: info: CoreStateMachine::getQueue Jul 11 23:01:41 volumio volumio[1136]: info: CorePlayQueue::getQueue Jul 11 23:01:44 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:44 volumio volumio[1136]: error: Error browsing14_a98c9024_7c3c493f:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"501"}],"errorDescription":[{"_":"Action Failed"}]}]}]}]}]}} Jul 11 23:01:44 volumio volumio[1136]: error: Failed to execute browseSource: Jul 11 23:01:51 volumio volumio[1136]: info: VolumeController::SetAlsaVolume13 Jul 11 23:01:51 volumio volumio[1136]: info: CoreStateMachine::pushState Jul 11 23:01:51 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 23:01:51 volumio volumio[1136]: info: CoreCommandRouter::volumioPushState Jul 11 23:01:51 volumio volumio[1136]: info: CoreCommandRouter::volumioGetQueue Jul 11 23:01:51 volumio volumio[1136]: info: CoreStateMachine::getQueue Jul 11 23:01:51 volumio volumio[1136]: info: CorePlayQueue::getQueue Jul 11 23:01:54 volumio volumio[1136]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 11 23:01:55 volumio volumio[1136]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 23:01:55 volumio volumio[1136]: TypeError: Cannot read property 'length' of undefined Jul 11 23:01:55 volumio volumio[1136]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 11 23:01:55 volumio volumio[1136]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 11 23:01:55 volumio volumio[1136]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 11 23:01:55 volumio volumio[1136]: at Parser.emit (events.js:400:28) Jul 11 23:01:55 volumio volumio[1136]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 11 23:01:55 volumio volumio[1136]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 11 23:01:55 volumio volumio[1136]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 11 23:01:55 volumio volumio[1136]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 11 23:01:55 volumio volumio[1136]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 11 23:01:55 volumio volumio[1136]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 11 23:01:55 volumio volumio[1136]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 11 23:01:55 volumio volumio[1136]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 11 23:01:55 volumio volumio[1136]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 11 23:01:55 volumio volumio[1136]: at IncomingMessage.emit (events.js:412:35) Jul 11 23:01:55 volumio volumio[1136]: at endReadableNT (internal/streams/readable.js:1333:12) Jul 11 23:01:55 volumio volumio[1136]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jul 11 23:01:55 volumio volumio[1136]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 23:01:55 volumio sudo[21753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-11 23:00 Jul 11 23:01:55 volumio sudo[21753]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:41:06 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="097e6b8b481766e7a0f9527e4a34a29b"