-- Logs begin at Thu 2019-02-14 21:11:58 AEDT, end at Fri 2025-04-25 11:18:51 AEST. -- Apr 25 11:17:00 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:01 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:05 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:07 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Apr 25 11:17:08 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 25 11:17:09 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:13 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:17 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:21 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:25 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 25 11:17:30 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 25 11:17:30 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:17:33 volumio volumio[1056]: info: CoreCommandRouter::volumioGetQueue Apr 25 11:17:33 volumio volumio[1056]: info: CoreStateMachine::getQueue Apr 25 11:17:33 volumio volumio[1056]: info: CorePlayQueue::getQueue Apr 25 11:17:37 volumio volumio[1056]: info: CoreCommandRouter::volumioGetState Apr 25 11:17:37 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:17:41 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:17:42 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:42 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:43 volumio volumio[1056]: error: error Apr 25 11:17:46 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:17:46 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:17:48 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:17:49 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:17:51 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:17:52 volumio volumio[1056]: Cannot compose Albumart path Apr 25 11:17:52 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:03 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:03 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7050 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7052 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7049 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7054 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7055 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7053 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7057 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7058 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7051 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7056 Apr 25 11:18:03 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7059 Apr 25 11:18:03 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7050 in service upnp_browser Apr 25 11:18:03 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7052 in service upnp_browser Apr 25 11:18:03 volumio volumio[1056]: info: No valid Plugin REST Endpoint Apr 25 11:18:03 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7049 in service upnp_browser Apr 25 11:18:03 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7054 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7055 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7053 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7057 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7058 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7051 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7056 in service upnp_browser Apr 25 11:18:04 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7059 in service upnp_browser Apr 25 11:18:05 volumio nmbd[914]: [2025/04/25 11:18:05.865957, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 25 11:18:05 volumio nmbd[914]: query_name_response: Multiple (2) responses received for a query on subnet 10.1.1.27 for name WORKGROUP<1d>. Apr 25 11:18:05 volumio nmbd[914]: This response was from IP 10.1.1.23, reporting an IP address of 10.1.1.23. Apr 25 11:18:06 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:06 volumio volumio[1056]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::ClearQueue Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::stop Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::clearPlayQueue Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::saveQueue Apr 25 11:18:06 volumio volumio[1056]: info: CoreCommandRouter::volumioPushQueue Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::addQueueItems Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::addQueueItems Apr 25 11:18:06 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:06 volumio volumio[1056]: info: Adding Item to queue: upnp/folder/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7142 Apr 25 11:18:06 volumio volumio[1056]: info: Exploding uri upnp/folder/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@7142 in service upnp_browser Apr 25 11:18:06 volumio volumio[1056]: info: CoreCommandRouter::volumioPushQueue Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::saveQueue Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::updateTrackBlock Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::getTrackBlock Apr 25 11:18:06 volumio volumio[1056]: info: CoreCommandRouter::volumioPlay Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::play index 0 Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::stop Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::play index undefined Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:06 volumio volumio[1056]: info: CoreStateMachine::startPlaybackTimer Apr 25 11:18:06 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:06 volumio volumio[1056]: info: [1745543886552] ControllerUPNPBrowser::clearAddPlayTrack Apr 25 11:18:06 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand stop Apr 25 11:18:06 volumio volumio[1056]: info: sendMpdCommand stop took 1 milliseconds Apr 25 11:18:06 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand clear Apr 25 11:18:06 volumio volumio[1056]: info: Apr 25 11:18:06 volumio volumio[1056]: ---------------------------- MPD announces system playlist update Apr 25 11:18:06 volumio volumio[1056]: info: Ignoring MPD Status Update Apr 25 11:18:06 volumio volumio[1056]: info: sendMpdCommand clear took 1 milliseconds Apr 25 11:18:06 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand load "http://10.1.1.23:8096/audio/7050/stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7" Apr 25 11:18:06 volumio volumio[1056]: error: updateQueue error: null Apr 25 11:18:06 volumio volumio[1056]: info: ------------------------------ 1ms Apr 25 11:18:06 volumio volumio[1056]: error: Upnp client error: Error: This socket has been ended by the other party Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand add "http://10.1.1.23:8096/audio/7050/stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7" Apr 25 11:18:07 volumio volumio[1056]: info: Apr 25 11:18:07 volumio volumio[1056]: ---------------------------- MPD announces system playlist update Apr 25 11:18:07 volumio volumio[1056]: info: Ignoring MPD Status Update Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand add "http://10.1.1.23:8096/audio/7050/stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7" took 0 milliseconds Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand play Apr 25 11:18:07 volumio volumio[1056]: info: ------------------------------ 1ms Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand play took 1 milliseconds Apr 25 11:18:07 volumio volumio[1056]: info: Apr 25 11:18:07 volumio volumio[1056]: ---------------------------- MPD announces state update: player Apr 25 11:18:07 volumio volumio[1056]: info: ControllerMpd::getState Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand status took 4 milliseconds Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::parseState Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 11:18:07 volumio volumio[1056]: info: Apr 25 11:18:07 volumio volumio[1056]: ---------------------------- MPD announces state update: player Apr 25 11:18:07 volumio volumio[1056]: info: ControllerMpd::getState Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand clearerror took 1 milliseconds Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo Apr 25 11:18:07 volumio volumio[1056]: info: ControllerMpd::pushState Apr 25 11:18:07 volumio volumio[1056]: info: CoreCommandRouter::servicePushState Apr 25 11:18:07 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:07 volumio volumio[1056]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":216,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7","artist":null,"album":null,"uri":"http://10.1.1.23:8096/audio/7050/stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7","trackType":""} Apr 25 11:18:07 volumio volumio[1056]: verbose: CURRENT POSITION 0 Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::syncState stateService pause Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus stop Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:07 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 11:18:07 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:07 volumio volumio[1056]: info: ------------------------------ 11ms Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand status took 7 milliseconds Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::parseState Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 11:18:07 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 25 11:18:07 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo Apr 25 11:18:07 volumio volumio[1056]: info: ControllerMpd::pushState Apr 25 11:18:07 volumio volumio[1056]: info: CoreCommandRouter::servicePushState Apr 25 11:18:07 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:07 volumio volumio[1056]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":216,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7","artist":null,"album":null,"uri":"http://10.1.1.23:8096/audio/7050/stream.flac?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=b67404a54c1189ef2ffb3f8095f4a92d&Static=true&PlaySessionId=f2da37892ca6f2a87bb8915d4d931760&api_key=68fc32ae7ef741eda78668b2089057a7","trackType":""} Apr 25 11:18:07 volumio volumio[1056]: verbose: CURRENT POSITION 0 Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::syncState stateService pause Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus stop Apr 25 11:18:07 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:07 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:07 volumio volumio[1056]: info: ------------------------------ 11ms Apr 25 11:18:18 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:18 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4671 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4680 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4673 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4672 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4674 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4679 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4681 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4677 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4676 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4678 Apr 25 11:18:18 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4675 Apr 25 11:18:18 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4671 in service upnp_browser Apr 25 11:18:18 volumio volumio[1056]: info: No valid Plugin REST Endpoint Apr 25 11:18:18 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4680 in service upnp_browser Apr 25 11:18:18 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4673 in service upnp_browser Apr 25 11:18:18 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4672 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4674 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4679 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4681 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4677 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4676 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4678 in service upnp_browser Apr 25 11:18:19 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@4675 in service upnp_browser Apr 25 11:18:26 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:26 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3150 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3152 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3143 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3151 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3155 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3144 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3149 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3146 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3147 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3145 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3153 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3148 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3142 Apr 25 11:18:26 volumio volumio[1056]: info: Preloading song: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3154 Apr 25 11:18:26 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3150 in service upnp_browser Apr 25 11:18:26 volumio volumio[1056]: info: No valid Plugin REST Endpoint Apr 25 11:18:26 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3152 in service upnp_browser Apr 25 11:18:26 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3143 in service upnp_browser Apr 25 11:18:26 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3151 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3155 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3144 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3149 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3146 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3147 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3145 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3153 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3148 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3142 in service upnp_browser Apr 25 11:18:27 volumio volumio[1056]: info: Exploding uri upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3154 in service upnp_browser Apr 25 11:18:28 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::ClearQueue Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::stop Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::clearPlayQueue Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::saveQueue Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushQueue Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::addQueueItems Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::addQueueItems Apr 25 11:18:28 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3150 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3150 Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushQueue Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::saveQueue Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::updateTrackBlock Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrackBlock Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPlay Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::play index 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::addQueueItems Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::addQueueItems Apr 25 11:18:28 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3152 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3152 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3143 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3143 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3151 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3151 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3155 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3155 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3144 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3144 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3149 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3149 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3146 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3146 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3147 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3147 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3145 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3145 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3153 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3153 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3148 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3148 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3142 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3142 Apr 25 11:18:28 volumio volumio[1056]: info: Adding Item to queue: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3154 Apr 25 11:18:28 volumio volumio[1056]: info: Using cached record of: upnp/http://10.1.1.23:8096/dlna/44b390a4-52dc-4a0e-b310-6ff473758f64/contentdirectory/control@3154 Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::stop Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushQueue Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::saveQueue Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::play index undefined Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::updateTrackBlock Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrackBlock Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::startPlaybackTimer Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: info: [1745543908211] ControllerUPNPBrowser::clearAddPlayTrack Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand stop Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand stop took 4 milliseconds Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand clear Apr 25 11:18:28 volumio volumio[1056]: info: Apr 25 11:18:28 volumio volumio[1056]: ---------------------------- MPD announces state update: player Apr 25 11:18:28 volumio volumio[1056]: info: Apr 25 11:18:28 volumio volumio[1056]: ---------------------------- MPD announces system playlist update Apr 25 11:18:28 volumio volumio[1056]: info: Ignoring MPD Status Update Apr 25 11:18:28 volumio volumio[1056]: info: ControllerMpd::getState Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand clear took 0 milliseconds Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand load "http://10.1.1.23:8096/audio/3150/stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7" Apr 25 11:18:28 volumio volumio[1056]: error: updateQueue error: null Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand status took 1 milliseconds Apr 25 11:18:28 volumio volumio[1056]: info: ------------------------------ 1ms Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::parseState Apr 25 11:18:28 volumio volumio[1056]: info: ControllerMpd::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::servicePushState Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 25 11:18:28 volumio volumio[1056]: verbose: CURRENT POSITION 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::syncState stateService stop Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus stop Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:28 volumio volumio[1056]: info: No code Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:28 volumio volumio[1056]: info: ------------------------------ 10ms Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand add "http://10.1.1.23:8096/audio/3150/stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7" Apr 25 11:18:28 volumio volumio[1056]: info: Apr 25 11:18:28 volumio volumio[1056]: ---------------------------- MPD announces system playlist update Apr 25 11:18:28 volumio volumio[1056]: info: Ignoring MPD Status Update Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand add "http://10.1.1.23:8096/audio/3150/stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7" took 0 milliseconds Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand play Apr 25 11:18:28 volumio volumio[1056]: info: ------------------------------ 1ms Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand play took 1 milliseconds Apr 25 11:18:28 volumio volumio[1056]: info: Apr 25 11:18:28 volumio volumio[1056]: ---------------------------- MPD announces state update: player Apr 25 11:18:28 volumio volumio[1056]: info: ControllerMpd::getState Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status Apr 25 11:18:28 volumio volumio[1056]: info: Apr 25 11:18:28 volumio volumio[1056]: ---------------------------- MPD announces state update: player Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand status took 4 milliseconds Apr 25 11:18:28 volumio volumio[1056]: info: ControllerMpd::getState Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand status Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::parseState Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand clearerror took 1 milliseconds Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand status took 1 milliseconds Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::parseState Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo Apr 25 11:18:28 volumio volumio[1056]: info: ControllerMpd::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::servicePushState Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7","artist":null,"album":null,"uri":"http://10.1.1.23:8096/audio/3150/stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7","trackType":""} Apr 25 11:18:28 volumio volumio[1056]: verbose: CURRENT POSITION 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::syncState stateService pause Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus stop Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:28 volumio volumio[1056]: info: ------------------------------ 10ms Apr 25 11:18:28 volumio volumio[1056]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 25 11:18:28 volumio volumio[1056]: verbose: ControllerMpd::parseTrackInfo Apr 25 11:18:28 volumio volumio[1056]: info: ControllerMpd::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::servicePushState Apr 25 11:18:28 volumio volumio[1056]: info: CorePlayQueue::getTrack 0 Apr 25 11:18:28 volumio volumio[1056]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7","artist":null,"album":null,"uri":"http://10.1.1.23:8096/audio/3150/stream.wav?DeviceProfileId=1e40b8cc86a04328970b3bd18c3453f6&DeviceId=7c6302e6e12d795de278178e416840ea&MediaSourceId=396039c31676d66601319ac0d4e442f8&Static=true&PlaySessionId=3e4fdd035f609a9b8f56cafc9ce966e3&api_key=68fc32ae7ef741eda78668b2089057a7","trackType":""} Apr 25 11:18:28 volumio volumio[1056]: verbose: CURRENT POSITION 0 Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::syncState stateService pause Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::syncState currentStatus stop Apr 25 11:18:28 volumio volumio[1056]: info: CoreStateMachine::pushState Apr 25 11:18:28 volumio volumio[1056]: info: CoreCommandRouter::volumioPushState Apr 25 11:18:28 volumio volumio[1056]: info: ------------------------------ 13ms Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:33 volumio volumio[1056]: error: error Apr 25 11:18:34 volumio volumio[1056]: error: error Apr 25 11:18:34 volumio volumio[1056]: error: error Apr 25 11:18:45 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:45 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:47 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:47 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:48 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:49 volumio volumio[1056]: info: Preload queue cleared Apr 25 11:18:51 volumio volumio[1056]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 11:18:51 volumio volumio[1056]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 25 11:18:51 volumio volumio[1056]: TypeError: Cannot read property 'length' of undefined Apr 25 11:18:51 volumio volumio[1056]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Apr 25 11:18:51 volumio volumio[1056]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Apr 25 11:18:51 volumio volumio[1056]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Apr 25 11:18:51 volumio volumio[1056]: at Parser.emit (events.js:315:20) Apr 25 11:18:51 volumio volumio[1056]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Apr 25 11:18:51 volumio volumio[1056]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Apr 25 11:18:51 volumio volumio[1056]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Apr 25 11:18:51 volumio volumio[1056]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Apr 25 11:18:51 volumio volumio[1056]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Apr 25 11:18:51 volumio volumio[1056]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Apr 25 11:18:51 volumio volumio[1056]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Apr 25 11:18:51 volumio volumio[1056]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Apr 25 11:18:51 volumio volumio[1056]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Apr 25 11:18:51 volumio volumio[1056]: at IncomingMessage.emit (events.js:327:22) Apr 25 11:18:51 volumio volumio[1056]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 25 11:18:51 volumio volumio[1056]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 25 11:18:51 volumio volumio[1056]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 25 11:18:51 volumio sudo[7965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-25 11:17 Apr 25 11:18:51 volumio sudo[7965]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"