-- Logs begin at Mon 2024-11-25 04:00:29 UTC, end at Tue 2024-11-26 08:32:49 UTC. -- Nov 26 08:31:00 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:31:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:31:01 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:31:01 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:01 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:31:03 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 26 08:31:03 volumio volumio[855]: info: CURURI: music-library Nov 26 08:31:03 volumio volumio[855]: error: Failed LSINFO: null Nov 26 08:31:03 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:09 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:09 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:11 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:11 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:13 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:14 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:16 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:19 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:25 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:25 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18055 Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18054 Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18057 Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18059 Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18060 Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18061 Nov 26 08:31:25 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18058 Nov 26 08:31:25 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18055 in service upnp_browser Nov 26 08:31:25 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18054 in service upnp_browser Nov 26 08:31:26 volumio volumio[855]: info: No valid Plugin REST Endpoint Nov 26 08:31:26 volumio volumio[855]: info: No valid Plugin REST Endpoint Nov 26 08:31:26 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18057 in service upnp_browser Nov 26 08:31:26 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18059 in service upnp_browser Nov 26 08:31:26 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18060 in service upnp_browser Nov 26 08:31:26 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18061 in service upnp_browser Nov 26 08:31:26 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18058 in service upnp_browser Nov 26 08:31:28 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::ClearQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::stop Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::clearPlayQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::saveQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::addQueueItems Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::addQueueItems Nov 26 08:31:28 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18055 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18055 Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::saveQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::updateTrackBlock Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrackBlock Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPlay Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::play index 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::addQueueItems Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::addQueueItems Nov 26 08:31:28 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18054 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18054 Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18057 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18057 Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18059 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18059 Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18060 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18060 Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18061 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18061 Nov 26 08:31:28 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18058 Nov 26 08:31:28 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@7_6523047f-18058 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::stop Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::saveQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::play index undefined Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::updateTrackBlock Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrackBlock Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::startPlaybackTimer Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: info: [1732609888407] ControllerUPNPBrowser::clearAddPlayTrack Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand stop Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand stop took 15 milliseconds Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand clear Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:31:28 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand clear took 3 milliseconds Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3" Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:31:28 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:31:28 volumio volumio[855]: error: updateQueue error: null Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 7ms Nov 26 08:31:28 volumio volumio[855]: error: Upnp client error: Error: This socket has been ended by the other party Nov 26 08:31:28 volumio volumio[855]: error: updateQueue error: null Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3" Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 60ms Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:31:28 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand add "http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3" took 2 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand play Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 3ms Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:31:28 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand play took 3 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 1ms Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:31:28 volumio volumio[855]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 26 08:31:28 volumio volumio[855]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 26 08:31:28 volumio volumio[855]: info: camilladsp stopping service pid 11882... Nov 26 08:31:28 volumio volumio[855]: info: camilladsp service terminated, instance 1 Nov 26 08:31:28 volumio volumio[855]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 26 08:31:28 volumio volumio[855]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 26 08:31:28 volumio volumio[855]: error: FusionDsp - ---- read samplerate skipped, rate is already updating; keeping 44100 Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand status took 56 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand status took 56 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:31:28 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand status took 12 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand status took 6 milliseconds Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":478,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Aja","artist":"Steely Dan","album":"Aja","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3","trackType":"mp3"} Nov 26 08:31:28 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus stop Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":478,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Aja","artist":"Steely Dan","album":"Aja","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3","trackType":"mp3"} Nov 26 08:31:28 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:31:28 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 93ms Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 95ms Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:31:28 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:31:28 volumio volumio[855]: info: Nov 26 08:31:28 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 31ms Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand status took 29 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand playlistinfo took 28 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand playlistinfo took 25 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 5ms Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":978,"duration":478,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Aja","artist":"Steely Dan","album":"Aja","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3","trackType":"mp3"} Nov 26 08:31:28 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:31:28 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":978,"duration":478,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Aja","artist":"Steely Dan","album":"Aja","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3","trackType":"mp3"} Nov 26 08:31:28 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:31:28 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 70ms Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 61ms Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand status took 77 milliseconds Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand playlistinfo took 73 milliseconds Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":978,"duration":478,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Aja","artist":"Steely Dan","album":"Aja","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3","trackType":"mp3"} Nov 26 08:31:28 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:31:28 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 122ms Nov 26 08:31:28 volumio volumio[855]: info: sendMpdCommand playlistinfo took 19 milliseconds Nov 26 08:31:28 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:31:28 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:31:28 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":978,"duration":478,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Aja","artist":"Steely Dan","album":"Aja","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_N182NTIzMDQ3Zi0xODA1NQ.mp3","trackType":"mp3"} Nov 26 08:31:28 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:31:28 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:28 volumio volumio[855]: info: ------------------------------ 114ms Nov 26 08:31:28 volumio volumio[855]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Nov 26 08:31:28 volumio volumio[855]: 2+0 records in Nov 26 08:31:28 volumio volumio[855]: 2+0 records out Nov 26 08:31:28 volumio volumio[855]: 65536 bytes (66 kB, 64 KiB) copied, 0.000994662 s, 65.9 MB/s Nov 26 08:31:28 volumio volumio[855]: info: camilladsp spawned new process with pid 17563, instance 1, run: true Nov 26 08:31:28 volumio volumio[855]: info: camilladsp service started and running in background, instance 1 Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:28 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:28 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:28 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 26 08:31:30 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:31:30 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:30 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:31:30 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:30 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:30 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:30 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:30 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 99 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 100 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 99 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 100 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 98 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 26 08:31:30 volumio volumio[855]: info: Setting Spotify Volume from Volumio: 98 Nov 26 08:31:30 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:31:30 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:31:30 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:30 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:30 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:31:30 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:31:31 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:31:31 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:31:31 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:31:31 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:31 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:31:31 volumio volumio[855]: SPOTIFY: SETTING SPOTIFY VOLUME 98 Nov 26 08:31:31 volumio volumio[855]: info: Sending Spotify command with payload to local API: /player/volume Nov 26 08:31:31 volumio go-librespot[1374]: time="2024-11-26T08:31:31Z" level=debug msg="update volume to 64224/65535" Nov 26 08:31:31 volumio go-librespot[1374]: time="2024-11-26T08:31:31Z" level=debug msg="renewing login5 access token" Nov 26 08:31:32 volumio go-librespot[1374]: time="2024-11-26T08:31:32Z" level=debug msg="authenticated as kk04yswtho3zrl5wzdmsxvlp0" Nov 26 08:31:32 volumio go-librespot[1374]: time="2024-11-26T08:31:32Z" level=debug msg="put connect state because VOLUME_CHANGED" Nov 26 08:31:32 volumio go-librespot[1374]: time="2024-11-26T08:31:32Z" level=trace msg="emitting websocket event: volume" Nov 26 08:31:32 volumio volumio[855]: SPOTIFY: received: {"type":"volume","data":{"value":98,"max":100}} Nov 26 08:31:32 volumio volumio[855]: SPOTIFY: RECEIVED SPOTIFY VOLUME 98 Nov 26 08:31:38 volumio sudo[17613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 26 08:31:38 volumio sudo[17613]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:38 volumio sudo[17613]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:38 volumio sudo[17616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 26 08:31:38 volumio sudo[17616]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:38 volumio sudo[17616]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:38 volumio volumio[855]: verbose: New Socket.io Connection to 192.168.178.65 from 192.168.178.52 UA: Mozilla/5.0 (Linux; Android 14; SM-A336B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.107 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 26 08:31:38 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 26 08:31:38 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 26 08:31:38 volumio sudo[17623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 26 08:31:38 volumio sudo[17623]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:38 volumio sudo[17623]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:38 volumio sudo[17625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 26 08:31:38 volumio sudo[17625]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:38 volumio sudo[17625]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:38 volumio volumio[855]: verbose: New Socket.io Connection to 192.168.178.65 from 192.168.178.52 UA: Mozilla/5.0 (Linux; Android 14; SM-A336B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.107 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Nov 26 08:31:38 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::volumioGetVisibleSources Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 26 08:31:39 volumio volumio[855]: info: Received Get System Info Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:31:39 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:39 volumio volumio[855]: info: Listing playlists Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 26 08:31:39 volumio volumio[855]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 26 08:31:40 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 26 08:31:40 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 26 08:31:40 volumio volumio[855]: info: Received Get System Info Nov 26 08:31:40 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:31:40 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:31:40 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:31:40 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:40 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:31:41 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 26 08:31:41 volumio volumio[855]: info: Received Get System Info Nov 26 08:31:41 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:31:41 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:31:41 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:31:41 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:41 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:31:42 volumio volumio[855]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 26 08:31:42 volumio volumio[855]: /bin/cat: /sys/class/net/wlan0/flags: No such file or directory Nov 26 08:31:42 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 26 08:31:42 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Nov 26 08:31:42 volumio sudo[17641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Nov 26 08:31:42 volumio sudo[17641]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:42 volumio sudo[17641]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:42 volumio sudo[17646]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Nov 26 08:31:42 volumio sudo[17646]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:42 volumio sudo[17653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Nov 26 08:31:42 volumio sudo[17653]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:42 volumio sudo[17646]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:42 volumio sudo[17653]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:42 volumio sudo[17663]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Nov 26 08:31:42 volumio sudo[17663]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:42 volumio sudo[17674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 26 08:31:42 volumio sudo[17674]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:42 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Nov 26 08:31:42 volumio sudo[17674]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:42 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Nov 26 08:31:42 volumio sudo[17663]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:42 volumio sudo[17680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 26 08:31:42 volumio sudo[17680]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:42 volumio sudo[17680]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:43 volumio sudo[17687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 26 08:31:43 volumio sudo[17687]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:43 volumio sudo[17687]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:43 volumio volumio[855]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Nov 26 08:31:43 volumio volumio[855]: wlan0 Interface doesn't support scanning. Nov 26 08:31:43 volumio volumio[855]: info: Cannot use regular scanning, forcing with ap-force Nov 26 08:31:43 volumio sudo[17692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Nov 26 08:31:43 volumio sudo[17692]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:31:43 volumio sudo[17692]: pam_unix(sudo:session): session closed for user root Nov 26 08:31:43 volumio volumio[855]: command failed: No such device (-19) Nov 26 08:31:43 volumio volumio[855]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Nov 26 08:31:43 volumio volumio[855]: command failed: No such device (-19) Nov 26 08:31:48 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:31:48 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:31:48 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:31:48 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:56 volumio volumio[855]: info: Preload queue cleared Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 26 08:31:56 volumio volumio[855]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 26 08:31:56 volumio volumio[855]: info: Received Get System Version Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 26 08:31:56 volumio volumio[855]: info: Received Get System Info Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:31:56 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:31:56 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:31:58 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:31:58 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:01 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:32:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:32:01 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:32:01 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:01 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:32:02 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:02 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:03 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:04 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:04 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305-4 Nov 26 08:32:04 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305-122 Nov 26 08:32:04 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305-13882 Nov 26 08:32:04 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305-4 in service upnp_browser Nov 26 08:32:04 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305-122 in service upnp_browser Nov 26 08:32:04 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305-13882 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:08 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29638 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29636 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29639 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29632 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29635 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29640 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29641 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29634 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29637 Nov 26 08:32:08 volumio volumio[855]: info: Preloading song: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29633 Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29638 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29636 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29639 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29632 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29635 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29640 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29641 in service upnp_browser Nov 26 08:32:08 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29634 in service upnp_browser Nov 26 08:32:09 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29637 in service upnp_browser Nov 26 08:32:09 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29633 in service upnp_browser Nov 26 08:32:10 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::ClearQueue Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::stop Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::stPlaybackTimer Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::updateTrackBlock Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrackBlock Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::serviceStop Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::serviceStop Nov 26 08:32:10 volumio volumio[855]: info: [1732609930906] ControllerUPNPBrowser::stop Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand stop Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::clearPlayQueue Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::saveQueue Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPushQueue Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::addQueueItems Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::addQueueItems Nov 26 08:32:10 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29638 Nov 26 08:32:10 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29638 Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPushQueue Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::saveQueue Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::updateTrackBlock Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrackBlock Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPlay Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::play index 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::addQueueItems Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::addQueueItems Nov 26 08:32:10 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29636 Nov 26 08:32:10 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29636 Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29639 Nov 26 08:32:10 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29639 Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29632 Nov 26 08:32:10 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29632 Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29635 Nov 26 08:32:10 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29635 Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29640 Nov 26 08:32:10 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29640 in service upnp_browser Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29641 Nov 26 08:32:10 volumio volumio[855]: info: Using cached record of: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29641 Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29634 Nov 26 08:32:10 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29634 in service upnp_browser Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29637 Nov 26 08:32:10 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29637 in service upnp_browser Nov 26 08:32:10 volumio volumio[855]: info: Adding Item to queue: upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29633 Nov 26 08:32:10 volumio volumio[855]: info: Exploding uri upnp/http://192.168.178.86:2869/upnphost/udhisapi.dll?control=uuid:b8091018-f768-4d4e-85ca-b6c899c5a883+urn:upnp-org:serviceId:ContentDirectory@14_4c634305_9d425a70-29633 in service upnp_browser Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::stop Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::play index undefined Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::startPlaybackTimer Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: [1732609930939] ControllerUPNPBrowser::clearAddPlayTrack Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand stop Nov 26 08:32:10 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:10 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:10 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:10 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:10 volumio volumio[855]: info: Nov 26 08:32:10 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:10 volumio volumio[855]: info: sendMpdCommand stop took 40 milliseconds Nov 26 08:32:10 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:10 volumio volumio[855]: info: sendMpdCommand stop took 10 milliseconds Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand clear Nov 26 08:32:10 volumio volumio[855]: info: Nov 26 08:32:10 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:10 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:10 volumio volumio[855]: info: Nov 26 08:32:10 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:32:10 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:32:10 volumio volumio[855]: info: sendMpdCommand status took 6 milliseconds Nov 26 08:32:10 volumio volumio[855]: info: sendMpdCommand clear took 6 milliseconds Nov 26 08:32:10 volumio volumio[855]: info: sendMpdCommand status took 3 milliseconds Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg" Nov 26 08:32:10 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:10 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: 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} Nov 26 08:32:10 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::syncState stateService stop Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus stop Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:10 volumio volumio[855]: info: No code Nov 26 08:32:10 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:10 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:10 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:10 volumio volumio[855]: info: ------------------------------ 29ms Nov 26 08:32:10 volumio volumio[855]: info: Nov 26 08:32:10 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:32:10 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:32:11 volumio volumio[855]: error: updateQueue error: null Nov 26 08:32:11 volumio volumio[855]: info: ------------------------------ 83ms Nov 26 08:32:11 volumio volumio[855]: info: sendMpdCommand playlistinfo took 81 milliseconds Nov 26 08:32:11 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:11 volumio volumio[855]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 26 08:32:11 volumio volumio[855]: info: ------------------------------ 94ms Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:11 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:11 volumio volumio[855]: 0+0 records in Nov 26 08:32:11 volumio volumio[855]: 0+0 records out Nov 26 08:32:11 volumio volumio[855]: 0 bytes copied, 9.7034e-05 s, 0.0 kB/s Nov 26 08:32:11 volumio volumio[855]: info: camilladsp spawned new process with pid 17814, instance 1, run: true Nov 26 08:32:12 volumio volumio[855]: info: CoreCommandRouter::volumioPushQueue Nov 26 08:32:12 volumio volumio[855]: info: CorePlayQueue::saveQueue Nov 26 08:32:12 volumio volumio[855]: info: CoreStateMachine::updateTrackBlock Nov 26 08:32:12 volumio volumio[855]: info: CorePlayQueue::getTrackBlock Nov 26 08:32:13 volumio volumio[855]: error: updateQueue error: null Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg" Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 2048ms Nov 26 08:32:13 volumio volumio[855]: Upnp client error: Error: This socket has been ended by the other party Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:32:13 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand add "http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg" took 5 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand play Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:32:13 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 6ms Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand play took 4 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 2ms Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:13 volumio volumio[855]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 26 08:32:13 volumio volumio[855]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 26 08:32:13 volumio volumio[855]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand status took 15 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand status took 14 milliseconds Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand status took 4 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand playlistinfo took 4 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand playlistinfo took 3 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand status took 2 milliseconds Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:13 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":238,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","artist":null,"album":null,"uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","trackType":""} Nov 26 08:32:13 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus stop Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:13 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":238,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","artist":null,"album":null,"uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","trackType":""} Nov 26 08:32:13 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:32:13 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 34ms Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 37ms Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:13 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":238,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","artist":null,"album":null,"uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","trackType":""} Nov 26 08:32:13 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:32:13 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:13 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":238,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","artist":null,"album":null,"uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","trackType":""} Nov 26 08:32:13 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:32:13 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 50ms Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 49ms Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: info: FusionDsp - eq1: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 25 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq2: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 40 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq3: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 63 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq4: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 100 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq5: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 160 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq6: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 250 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq7: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 400 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq8: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 630 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq9: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 1000 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq10: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 1600 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq11: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 2500 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq12: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 4000 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq13: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 6300 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq14: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 10000 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: eq15: Nov 26 08:32:13 volumio volumio[855]: type: Biquad Nov 26 08:32:13 volumio volumio[855]: parameters: Nov 26 08:32:13 volumio volumio[855]: type: Peaking Nov 26 08:32:13 volumio volumio[855]: freq: 16000 Nov 26 08:32:13 volumio volumio[855]: q: 1.85 Nov 26 08:32:13 volumio volumio[855]: gain: 0 Nov 26 08:32:13 volumio volumio[855]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:32:13 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces system playlist update Nov 26 08:32:13 volumio volumio[855]: info: Ignoring MPD Status Update Nov 26 08:32:13 volumio volumio[855]: info: Nov 26 08:32:13 volumio volumio[855]: ---------------------------- MPD announces state update: player Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::getState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand status Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 9ms Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand status took 5 milliseconds Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 4ms Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand status took 4 milliseconds Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseState Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:13 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1104,"duration":238,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1399 Kbps","isStreaming":false,"title":"Big Ideas","artist":"Arctic Monkeys","album":"The Car","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","trackType":""} Nov 26 08:32:13 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:32:13 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 29ms Nov 26 08:32:13 volumio volumio[855]: info: sendMpdCommand playlistinfo took 21 milliseconds Nov 26 08:32:13 volumio volumio[855]: verbose: ControllerMpd::parseTrackInfo Nov 26 08:32:13 volumio volumio[855]: info: ControllerMpd::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::servicePushState Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getTrack 0 Nov 26 08:32:13 volumio volumio[855]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1104,"duration":238,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1399 Kbps","isStreaming":false,"title":"Big Ideas","artist":"Arctic Monkeys","album":"The Car","uri":"http://192.168.178.86:10243/WMPNSSv4/1320349966/0_MTRfNGM2MzQzMDVfOWQ0MjVhNzAtMjk2Mzg","trackType":""} Nov 26 08:32:13 volumio volumio[855]: verbose: CURRENT POSITION 0 Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState stateService play Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::syncState currentStatus play Nov 26 08:32:13 volumio volumio[855]: info: Received an update from plugin. extracting info from payload Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:13 volumio volumio[855]: info: ------------------------------ 58ms Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:13 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:13 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 97 Nov 26 08:32:13 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:16 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:32:16 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:16 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:16 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:16 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:16 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:16 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:16 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Nov 26 08:32:16 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 98 Nov 26 08:32:16 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 96 Nov 26 08:32:16 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 26 08:32:16 volumio volumio[855]: info: Setting Spotify Volume from Volumio: 96 Nov 26 08:32:17 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:32:17 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:17 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:17 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:17 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:17 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:17 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 96 Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 95 Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:17 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:32:17 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:17 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:17 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:17 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:17 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:17 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 94 Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 96 Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 94 Nov 26 08:32:17 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 26 08:32:17 volumio volumio[855]: info: Setting Spotify Volume from Volumio: 94 Nov 26 08:32:18 volumio volumio[855]: info: VolumeController::SetAlsaVolume- Nov 26 08:32:18 volumio volumio[855]: info: CoreStateMachine::pushState Nov 26 08:32:18 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 08:32:18 volumio volumio[855]: info: CoreCommandRouter::volumioPushState Nov 26 08:32:18 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:18 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:18 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:18 volumio volumio[855]: SPOTIFY: RECEIVED VOLUMIO VOLUME 93 Nov 26 08:32:18 volumio volumio[855]: SPOTIFY: SPOTIFY VOLUME 94 Nov 26 08:32:18 volumio volumio[855]: SPOTIFY: VOLUMIO VOLUME 93 Nov 26 08:32:18 volumio volumio[855]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 26 08:32:19 volumio volumio[855]: SPOTIFY: SETTING SPOTIFY VOLUME 94 Nov 26 08:32:19 volumio volumio[855]: info: Sending Spotify command with payload to local API: /player/volume Nov 26 08:32:19 volumio go-librespot[1374]: time="2024-11-26T08:32:19Z" level=debug msg="update volume to 61602/65535" Nov 26 08:32:19 volumio go-librespot[1374]: time="2024-11-26T08:32:19Z" level=debug msg="put connect state because VOLUME_CHANGED" Nov 26 08:32:19 volumio go-librespot[1374]: time="2024-11-26T08:32:19Z" level=trace msg="emitting websocket event: volume" Nov 26 08:32:19 volumio volumio[855]: SPOTIFY: received: {"type":"volume","data":{"value":94,"max":100}} Nov 26 08:32:19 volumio volumio[855]: SPOTIFY: RECEIVED SPOTIFY VOLUME 94 Nov 26 08:32:27 volumio sudo[17939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 26 08:32:27 volumio sudo[17939]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:32:27 volumio sudo[17939]: pam_unix(sudo:session): session closed for user root Nov 26 08:32:27 volumio sudo[17941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 26 08:32:27 volumio sudo[17941]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:32:27 volumio sudo[17941]: pam_unix(sudo:session): session closed for user root Nov 26 08:32:27 volumio volumio[855]: verbose: New Socket.io Connection to 192.168.178.65 from 192.168.178.52 UA: Mozilla/5.0 (Linux; Android 14; SM-A336B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.107 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Nov 26 08:32:27 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 26 08:32:27 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 26 08:32:27 volumio sudo[17947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 26 08:32:27 volumio sudo[17947]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:32:27 volumio sudo[17947]: pam_unix(sudo:session): session closed for user root Nov 26 08:32:27 volumio sudo[17950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 26 08:32:27 volumio sudo[17950]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 26 08:32:27 volumio sudo[17950]: pam_unix(sudo:session): session closed for user root Nov 26 08:32:28 volumio volumio[855]: verbose: New Socket.io Connection to 192.168.178.65 from 192.168.178.52 UA: Mozilla/5.0 (Linux; Android 14; SM-A336B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.107 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetVisibleSources Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 26 08:32:28 volumio volumio[855]: info: Received Get System Info Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:32:28 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:28 volumio volumio[855]: info: Listing playlists Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 26 08:32:28 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 26 08:32:29 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 26 08:32:29 volumio volumio[855]: info: Received Get System Info Nov 26 08:32:29 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:32:29 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:32:29 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:32:29 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:29 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:32:29 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 26 08:32:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 26 08:32:30 volumio volumio[855]: info: Received Get System Info Nov 26 08:32:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:32:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:32:30 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:32:30 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:30 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:32:31 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:32:31 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:32:31 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:32:31 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:31 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:32:32 volumio volumio[855]: info: CoreCommandRouter::volumioGetQueue Nov 26 08:32:32 volumio volumio[855]: info: CoreStateMachine::getQueue Nov 26 08:32:32 volumio volumio[855]: info: CorePlayQueue::getQueue Nov 26 08:32:35 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 26 08:32:35 volumio volumio[855]: info: CURURI: music-library Nov 26 08:32:35 volumio volumio[855]: error: Failed LSINFO: null Nov 26 08:32:35 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:38 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 26 08:32:39 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:39 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:40 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:40 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:43 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:43 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:45 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:45 volumio volumio[855]: info: Preload queue cleared Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 26 08:32:46 volumio volumio[855]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 26 08:32:46 volumio volumio[855]: info: Received Get System Version Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 26 08:32:46 volumio volumio[855]: info: Received Get System Info Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 26 08:32:46 volumio volumio[855]: info: Discovery: Getting this device information Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::volumioGetState Nov 26 08:32:46 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 26 08:32:48 volumio volumio[855]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 26 08:32:48 volumio volumio[855]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 26 08:32:48 volumio volumio[855]: TypeError: Cannot read property 'length' of undefined Nov 26 08:32:48 volumio volumio[855]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 26 08:32:48 volumio volumio[855]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 26 08:32:48 volumio volumio[855]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 26 08:32:48 volumio volumio[855]: at Parser.emit (events.js:400:28) Nov 26 08:32:48 volumio volumio[855]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 26 08:32:48 volumio volumio[855]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 26 08:32:48 volumio volumio[855]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 26 08:32:48 volumio volumio[855]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 26 08:32:48 volumio volumio[855]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 26 08:32:48 volumio volumio[855]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 26 08:32:48 volumio volumio[855]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 26 08:32:48 volumio volumio[855]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 26 08:32:48 volumio volumio[855]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 26 08:32:48 volumio volumio[855]: at IncomingMessage.emit (events.js:412:35) Nov 26 08:32:48 volumio volumio[855]: at endReadableNT (internal/streams/readable.js:1333:12) Nov 26 08:32:48 volumio volumio[855]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Nov 26 08:32:48 volumio volumio[855]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 26 08:32:49 volumio sudo[18052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-26 08:31 Nov 26 08:32:49 volumio sudo[18052]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"