-- Logs begin at Thu 2019-02-14 10:11:59 WET, end at Sun 2024-07-07 15:25:52 WEST. -- Jul 07 15:24:24 volumio volumio[906]: info: CorePlayQueue::getTrack 4 Jul 07 15:24:24 volumio volumio[906]: info: CorePlayQueue::getTrack 5 Jul 07 15:24:24 volumio volumio[906]: info: Prefetching next song Jul 07 15:24:24 volumio volumio[906]: info: [1720362264438] ControllerTidal::prefetch Jul 07 15:24:24 volumio volumio[906]: info: Getting stream with soundQuality LOSSLESS Jul 07 15:24:24 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/370115962&soundQuality=LOSSLESS" Jul 07 15:24:24 volumio volumio[906]: info: Jul 07 15:24:24 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:24:24 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:24:24 volumio volumio[906]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/370115962&soundQuality=LOSSLESS" took 1 milliseconds Jul 07 15:24:24 volumio volumio[906]: STREAMING PROXY: Handling url /?data=tidal://song/370115962&soundQuality=LOSSLESS Jul 07 15:24:24 volumio volumio[906]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 07 15:24:24 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand consume 1 Jul 07 15:24:24 volumio volumio[906]: info: Jul 07 15:24:24 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:24:24 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:24:24 volumio volumio[906]: info: ------------------------------ 3ms Jul 07 15:24:24 volumio volumio[906]: info: sendMpdCommand consume 1 took 2 milliseconds Jul 07 15:24:24 volumio volumio[906]: info: ------------------------------ 2ms Jul 07 15:24:24 volumio volumio[906]: info: Executing endpoint getStreamUrltidal Jul 07 15:24:24 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Jul 07 15:24:24 volumio volumio[906]: info: getStreamUrl took 325 milliseconds Jul 07 15:24:24 volumio volumio[906]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5ZTRkNWEyYTk2Yzk0ZTEyN2YzZDBlMTJiYTZmNWZjZC5tcDQ/0.flac?Expires=1720365864&Signature=DsWwXOnHBdS~j~N-~MCLfFoGeCh89wpfZQlfE6tbYM6uYGPGkD1MsGXWEz8yoN3HUmhLZS9bJ5en~EwIUNdV50RhprT6ea-p3sptvjA0y~aKgPUNNXmY3u71UXHTTRyyo6khVw8q41UHdiw4-YknNWq2khPgm~kzjJpZYYefvodbA-R9eutZIN6-9qLmxpbyt-JEzxLVpioQUfhzhmuB--xPj8473USvXjVNoYWMGqye89az6uI3UKqKUPzvHPRswR6hUL0Jb9p1LzWzr4Lp667ceORVxrAvb4chWyqTrpCFE0NSbU9G87oHU2RTDPsIqVG1dtYWf6nChGVGIBBTaQ__&Key-Pair-Id=K14LZCZ9QUI4JL Jul 07 15:24:24 volumio volumio[906]: STREAMING PROXY: Response: 200, length: 22740898 Jul 07 15:24:26 volumio volumio[906]: STREAMING PROXY: Client dropped request, destroying Jul 07 15:24:27 volumio volumio[906]: info: Jul 07 15:24:27 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:24:27 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:24:27 volumio volumio[906]: info: Jul 07 15:24:27 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:24:27 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:24:27 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:24:27 volumio volumio[906]: info: Jul 07 15:24:27 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:24:27 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:24:27 volumio volumio[906]: info: Jul 07 15:24:27 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:24:27 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:24:27 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:24:27 volumio volumio[906]: info: ------------------------------ 7ms Jul 07 15:24:28 volumio volumio[906]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 07 15:24:28 volumio volumio[906]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 07 15:24:28 volumio volumio[906]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 07 15:24:28 volumio volumio[906]: info: Jul 07 15:24:28 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand status took 1715 milliseconds Jul 07 15:24:28 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:24:28 volumio volumio[906]: info: ------------------------------ 1715ms Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand status took 1713 milliseconds Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:24:28 volumio volumio[906]: info: Jul 07 15:24:28 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:24:28 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand status took 4 milliseconds Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand status took 2 milliseconds Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:24:28 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:24:28 volumio volumio[906]: info: CorePlayQueue::getTrack 4 Jul 07 15:24:28 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":180,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1020 Kbps","isStreaming":false,"title":"370115962&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/370115962&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:24:28 volumio volumio[906]: verbose: CURRENT POSITION 4 Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:24:28 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:24:28 volumio volumio[906]: info: CorePlayQueue::getTrack 4 Jul 07 15:24:28 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":180,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"941 Kbps","isStreaming":false,"title":"370115962&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/370115962&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:24:28 volumio volumio[906]: verbose: CURRENT POSITION 4 Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:24:28 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: ------------------------------ 1740ms Jul 07 15:24:28 volumio volumio[906]: info: ------------------------------ 1738ms Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand playlistinfo took 20 milliseconds Jul 07 15:24:28 volumio volumio[906]: info: sendMpdCommand playlistinfo took 19 milliseconds Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:24:28 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:24:28 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:24:28 volumio volumio[906]: info: CorePlayQueue::getTrack 4 Jul 07 15:24:28 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":180,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"862 Kbps","isStreaming":false,"title":"370115962&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/370115962&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:24:28 volumio volumio[906]: verbose: CURRENT POSITION 4 Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:24:28 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:24:28 volumio volumio[906]: info: CorePlayQueue::getTrack 4 Jul 07 15:24:28 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":180,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"862 Kbps","isStreaming":false,"title":"370115962&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/370115962&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:24:28 volumio volumio[906]: verbose: CURRENT POSITION 4 Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:24:28 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:28 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:28 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:28 volumio volumio[906]: info: ------------------------------ 40ms Jul 07 15:24:28 volumio volumio[906]: info: ------------------------------ 37ms Jul 07 15:24:28 volumio volumio[906]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 07 15:24:28 volumio volumio[906]: info: CoreStateMachine::startPlaybackTimer Jul 07 15:24:28 volumio volumio[906]: info: CorePlayQueue::getTrack 5 Jul 07 15:24:29 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:24:29 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:24:29 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:24:29 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:24:29 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:24:47 volumio volumio[906]: info: camilladsp spawned new process with pid 12838, instance 1, run: true Jul 07 15:24:47 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:24:47 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 128, in _query Jul 07 15:24:47 volumio volumio[4134]: rawrepl = self._ws.recv() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 362, in recv Jul 07 15:24:47 volumio volumio[4134]: opcode, data = self.recv_data() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 385, in recv_data Jul 07 15:24:47 volumio volumio[4134]: opcode, frame = self.recv_data_frame(control_frame) Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 406, in recv_data_frame Jul 07 15:24:47 volumio volumio[4134]: frame = self.recv_frame() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 445, in recv_frame Jul 07 15:24:47 volumio volumio[4134]: return self.frame_buffer.recv_frame() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_abnf.py", line 338, in recv_frame Jul 07 15:24:47 volumio volumio[4134]: self.recv_header() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_abnf.py", line 294, in recv_header Jul 07 15:24:47 volumio volumio[4134]: header = self.recv_strict(2) Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_abnf.py", line 373, in recv_strict Jul 07 15:24:47 volumio volumio[4134]: bytes_ = self.recv(min(16384, shortage)) Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 529, in _recv Jul 07 15:24:47 volumio volumio[4134]: return recv(self.sock, bufsize) Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_socket.py", line 123, in recv Jul 07 15:24:47 volumio volumio[4134]: "Connection to remote host was lost.") Jul 07 15:24:47 volumio volumio[4134]: websocket._exceptions.WebSocketConnectionClosedException: Connection to remote host was lost. Jul 07 15:24:47 volumio volumio[4134]: During handling of the above exception, another exception occurred: Jul 07 15:24:47 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:24:47 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:24:47 volumio volumio[4134]: resp = await task Jul 07 15:24:47 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:24:47 volumio volumio[4134]: resp = await handler(request) Jul 07 15:24:47 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 90, in get_param Jul 07 15:24:47 volumio volumio[4134]: result = cdsp.get_volume() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 276, in get_volume Jul 07 15:24:47 volumio volumio[4134]: vol = self._query("GetVolume") Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 131, in _query Jul 07 15:24:47 volumio volumio[4134]: raise IOError("Lost connection to CamillaDSP") Jul 07 15:24:47 volumio volumio[4134]: OSError: Lost connection to CamillaDSP Jul 07 15:24:47 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:24:47 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:24:47 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:24:47 volumio volumio[4134]: resp = await task Jul 07 15:24:47 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:24:47 volumio volumio[4134]: resp = await handler(request) Jul 07 15:24:47 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 92, in get_param Jul 07 15:24:47 volumio volumio[4134]: result = cdsp.get_mute() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 289, in get_mute Jul 07 15:24:47 volumio volumio[4134]: mute = self._query("GetMute") Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 134, in _query Jul 07 15:24:47 volumio volumio[4134]: raise IOError("Not connected to CamillaDSP") Jul 07 15:24:47 volumio volumio[4134]: OSError: Not connected to CamillaDSP Jul 07 15:24:47 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:24:47 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:24:47 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:24:47 volumio volumio[4134]: resp = await task Jul 07 15:24:47 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:24:47 volumio volumio[4134]: resp = await handler(request) Jul 07 15:24:47 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 90, in get_param Jul 07 15:24:47 volumio volumio[4134]: result = cdsp.get_volume() Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 276, in get_volume Jul 07 15:24:47 volumio volumio[4134]: vol = self._query("GetVolume") Jul 07 15:24:47 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 134, in _query Jul 07 15:24:47 volumio volumio[4134]: raise IOError("Not connected to CamillaDSP") Jul 07 15:24:47 volumio volumio[4134]: OSError: Not connected to CamillaDSP Jul 07 15:24:56 volumio volumio[906]: info: camilladsp spawned new process with pid 12850, instance 1, run: true Jul 07 15:25:05 volumio volumio[906]: info: camilladsp spawned new process with pid 12863, instance 1, run: true Jul 07 15:25:05 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:25:05 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 128, in _query Jul 07 15:25:05 volumio volumio[4134]: rawrepl = self._ws.recv() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 362, in recv Jul 07 15:25:05 volumio volumio[4134]: opcode, data = self.recv_data() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 385, in recv_data Jul 07 15:25:05 volumio volumio[4134]: opcode, frame = self.recv_data_frame(control_frame) Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 406, in recv_data_frame Jul 07 15:25:05 volumio volumio[4134]: frame = self.recv_frame() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 445, in recv_frame Jul 07 15:25:05 volumio volumio[4134]: return self.frame_buffer.recv_frame() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_abnf.py", line 338, in recv_frame Jul 07 15:25:05 volumio volumio[4134]: self.recv_header() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_abnf.py", line 294, in recv_header Jul 07 15:25:05 volumio volumio[4134]: header = self.recv_strict(2) Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_abnf.py", line 373, in recv_strict Jul 07 15:25:05 volumio volumio[4134]: bytes_ = self.recv(min(16384, shortage)) Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_core.py", line 529, in _recv Jul 07 15:25:05 volumio volumio[4134]: return recv(self.sock, bufsize) Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/websocket/_socket.py", line 123, in recv Jul 07 15:25:05 volumio volumio[4134]: "Connection to remote host was lost.") Jul 07 15:25:05 volumio volumio[4134]: websocket._exceptions.WebSocketConnectionClosedException: Connection to remote host was lost. Jul 07 15:25:05 volumio volumio[4134]: During handling of the above exception, another exception occurred: Jul 07 15:25:05 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:25:05 volumio volumio[4134]: resp = await task Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:25:05 volumio volumio[4134]: resp = await handler(request) Jul 07 15:25:05 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 90, in get_param Jul 07 15:25:05 volumio volumio[4134]: result = cdsp.get_volume() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 276, in get_volume Jul 07 15:25:05 volumio volumio[4134]: vol = self._query("GetVolume") Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 131, in _query Jul 07 15:25:05 volumio volumio[4134]: raise IOError("Lost connection to CamillaDSP") Jul 07 15:25:05 volumio volumio[4134]: OSError: Lost connection to CamillaDSP Jul 07 15:25:05 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:25:05 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:25:05 volumio volumio[4134]: resp = await task Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:25:05 volumio volumio[4134]: resp = await handler(request) Jul 07 15:25:05 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 92, in get_param Jul 07 15:25:05 volumio volumio[4134]: result = cdsp.get_mute() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 289, in get_mute Jul 07 15:25:05 volumio volumio[4134]: mute = self._query("GetMute") Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 134, in _query Jul 07 15:25:05 volumio volumio[4134]: raise IOError("Not connected to CamillaDSP") Jul 07 15:25:05 volumio volumio[4134]: OSError: Not connected to CamillaDSP Jul 07 15:25:05 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:25:05 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:25:05 volumio volumio[4134]: resp = await task Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:25:05 volumio volumio[4134]: resp = await handler(request) Jul 07 15:25:05 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 90, in get_param Jul 07 15:25:05 volumio volumio[4134]: result = cdsp.get_volume() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 276, in get_volume Jul 07 15:25:05 volumio volumio[4134]: vol = self._query("GetVolume") Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 134, in _query Jul 07 15:25:05 volumio volumio[4134]: raise IOError("Not connected to CamillaDSP") Jul 07 15:25:05 volumio volumio[4134]: OSError: Not connected to CamillaDSP Jul 07 15:25:05 volumio volumio[4134]: ERROR:aiohttp.server:Error handling request Jul 07 15:25:05 volumio volumio[4134]: Traceback (most recent call last): Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_protocol.py", line 406, in start Jul 07 15:25:05 volumio volumio[4134]: resp = await task Jul 07 15:25:05 volumio volumio[4134]: File "/usr/lib/python3/dist-packages/aiohttp/web_app.py", line 435, in _handle Jul 07 15:25:05 volumio volumio[4134]: resp = await handler(request) Jul 07 15:25:05 volumio volumio[4134]: File "/data/plugins/audio_interface/fusiondsp/cgui/backend/views.py", line 92, in get_param Jul 07 15:25:05 volumio volumio[4134]: result = cdsp.get_mute() Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 289, in get_mute Jul 07 15:25:05 volumio volumio[4134]: mute = self._query("GetMute") Jul 07 15:25:05 volumio volumio[4134]: File "/usr/local/lib/python3.7/dist-packages/camilladsp/camilladsp.py", line 134, in _query Jul 07 15:25:05 volumio volumio[4134]: raise IOError("Not connected to CamillaDSP") Jul 07 15:25:05 volumio volumio[4134]: OSError: Not connected to CamillaDSP Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::volumioNext Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::next Jul 07 15:25:19 volumio volumio[906]: info: [1720362319602] ControllerTidal::next Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::next Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::stop Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::stPlaybackTimer Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::updateTrackBlock Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrackBlock Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrack 5 Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:19 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:19 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::serviceStop Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrack 5 Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::serviceStop Jul 07 15:25:19 volumio volumio[906]: info: [1720362319607] ControllerTidal::stop Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 07 15:25:19 volumio volumio[906]: info: ControllerMpd::stop Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand stop Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand stop took 8 milliseconds Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::play index undefined Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::startPlaybackTimer Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:19 volumio volumio[906]: info: [1720362319617] ControllerTidal::clearAddPlayTrack Jul 07 15:25:19 volumio volumio[906]: info: Getting stream with soundQuality LOSSLESS Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand stop Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::updateTrackBlock Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrackBlock Jul 07 15:25:19 volumio volumio[906]: info: Jul 07 15:25:19 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:25:19 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand stop took 3 milliseconds Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand clear Jul 07 15:25:19 volumio volumio[906]: info: Jul 07 15:25:19 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:25:19 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:25:19 volumio volumio[906]: info: Jul 07 15:25:19 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:25:19 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand status took 2 milliseconds Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand clear took 1 milliseconds Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand status took 2 milliseconds Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/372019653&soundQuality=LOSSLESS" Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:25:19 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:19 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:19 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:19 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:19 volumio volumio[906]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Jul 07 15:25:19 volumio volumio[906]: info: ------------------------------ 10ms Jul 07 15:25:19 volumio volumio[906]: info: Jul 07 15:25:19 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:25:19 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:25:19 volumio volumio[906]: error: updateQueue error: null Jul 07 15:25:19 volumio volumio[906]: info: Jul 07 15:25:19 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:25:19 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:25:19 volumio volumio[906]: info: ------------------------------ 12ms Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand playlistinfo took 11 milliseconds Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/372019653&soundQuality=LOSSLESS" took 11 milliseconds Jul 07 15:25:19 volumio volumio[906]: info: ------------------------------ 3ms Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:25:19 volumio volumio[906]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 07 15:25:19 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand play Jul 07 15:25:19 volumio volumio[906]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 07 15:25:19 volumio volumio[906]: info: ------------------------------ 16ms Jul 07 15:25:19 volumio volumio[906]: info: Jul 07 15:25:19 volumio volumio[906]: ---------------------------- MPD announces system playlist update Jul 07 15:25:19 volumio volumio[906]: STREAMING PROXY: Handling url /?data=tidal://song/372019653&soundQuality=LOSSLESS Jul 07 15:25:19 volumio volumio[906]: info: Ignoring MPD Status Update Jul 07 15:25:19 volumio volumio[906]: info: ------------------------------ 6ms Jul 07 15:25:19 volumio volumio[906]: info: sendMpdCommand play took 4 milliseconds Jul 07 15:25:19 volumio volumio[906]: info: ------------------------------ 2ms Jul 07 15:25:19 volumio volumio[906]: info: Executing endpoint getStreamUrltidal Jul 07 15:25:19 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Jul 07 15:25:19 volumio volumio[906]: info: getStreamUrl took 338 milliseconds Jul 07 15:25:19 volumio volumio[906]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiRmMTAxMDNjMzBjODNlN2Q1NzJhNWUxOTM0ZjE5Zjc1Mi5tcDQ/0.flac?Expires=1720365919&Signature=sm0lJe6ToBxT84ERZFTeMFmPnqz8IGl8qiZ-eropi7TRruU5RsgEVnZnDeR8L-hpSWrSxoQhWefobP4EhfoOXzeKfbIhtfGVYOyxHDrv2a0HnKSyLZrTtHGKzlIX3-N9RN9ltIKe8uPlT~XVHgk7Hz5PHA-gSKdtWtVczB3Jq9wAgrBvDoeIlUX1lzWzAj7bNCzauU2VP3oaJKkxUT~BikJZ77Iet1S9xBYRTZKnecfbNHVreRMj4U11~Qml31L40mtSOKukG9H1Fexxy6tDq0p6vewafdZzmUu~IBkGWOL1Tgj0spkgu0pbuJB64EAOcj~JzJM-rjjHeHsDV1odJA__&Key-Pair-Id=K14LZCZ9QUI4JL Jul 07 15:25:20 volumio volumio[906]: STREAMING PROXY: Response: 200, length: 17987091 Jul 07 15:25:20 volumio volumio[906]: info: Jul 07 15:25:20 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:25:20 volumio volumio[906]: info: Jul 07 15:25:20 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 07 15:25:20 volumio volumio[906]: info: Jul 07 15:25:20 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand status took 27 milliseconds Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand status took 27 milliseconds Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:25:20 volumio volumio[906]: info: Jul 07 15:25:20 volumio volumio[906]: ---------------------------- MPD announces state update: player Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::getState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand status Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand status took 3 milliseconds Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand status took 2 milliseconds Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseState Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:25:20 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:20 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":162,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"372019653&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/372019653&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:25:20 volumio volumio[906]: verbose: CURRENT POSITION 6 Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus stop Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:25:20 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:20 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":162,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"372019653&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/372019653&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:25:20 volumio volumio[906]: verbose: CURRENT POSITION 6 Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:25:20 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:20 volumio volumio[906]: info: ------------------------------ 43ms Jul 07 15:25:20 volumio volumio[906]: info: ------------------------------ 47ms Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand playlistinfo took 17 milliseconds Jul 07 15:25:20 volumio volumio[906]: info: sendMpdCommand playlistinfo took 16 milliseconds Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:25:20 volumio volumio[906]: verbose: ControllerMpd::parseTrackInfo Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:25:20 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:20 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1166,"duration":162,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"850 Kbps","isStreaming":false,"title":"372019653&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/372019653&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:25:20 volumio volumio[906]: verbose: CURRENT POSITION 6 Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:25:20 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:20 volumio volumio[906]: info: ControllerMpd::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::servicePushState Jul 07 15:25:20 volumio volumio[906]: info: CorePlayQueue::getTrack 6 Jul 07 15:25:20 volumio volumio[906]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1166,"duration":162,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"850 Kbps","isStreaming":false,"title":"372019653&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/372019653&soundQuality=LOSSLESS","trackType":"tidal"} Jul 07 15:25:20 volumio volumio[906]: verbose: CURRENT POSITION 6 Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState stateService play Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::syncState currentStatus play Jul 07 15:25:20 volumio volumio[906]: info: Received an update from plugin. extracting info from payload Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:20 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:20 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:20 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:20 volumio volumio[906]: info: ------------------------------ 41ms Jul 07 15:25:20 volumio volumio[906]: info: ------------------------------ 39ms Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 07 15:25:20 volumio volumio[906]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 07 15:25:20 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Jul 07 15:25:20 volumio volumio[906]: info: camilladsp spawned new process with pid 12876, instance 1, run: true Jul 07 15:25:21 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 07 15:25:21 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 07 15:25:21 volumio volumio[906]: info: Discovery: Getting this device information Jul 07 15:25:21 volumio volumio[906]: info: CoreCommandRouter::volumioGetState Jul 07 15:25:21 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 07 15:25:21 volumio volumio[906]: STREAMING PROXY: Client dropped request, destroying Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: metavolumio , setInfinityPlayback Jul 07 15:25:30 volumio volumio[906]: info: METAVOLUMIO: Enabling Infinity Playback Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::volumioGetState Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::volumioRandom Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::writePlayerControls Jul 07 15:25:30 volumio volumio[906]: info: CoreStateMachine::setRepeat false single false Jul 07 15:25:30 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:25:30 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:30 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:30 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:31 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: metavolumio , setInfinityPlayback Jul 07 15:25:31 volumio volumio[906]: info: METAVOLUMIO: Disabling Infinity Playback Jul 07 15:25:31 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 07 15:25:31 volumio volumio[906]: info: CoreCommandRouter::volumioRandom Jul 07 15:25:31 volumio volumio[906]: info: CoreCommandRouter::writePlayerControls Jul 07 15:25:31 volumio volumio[906]: info: CoreStateMachine::setRepeat false single false Jul 07 15:25:31 volumio volumio[906]: info: CoreStateMachine::pushState Jul 07 15:25:31 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 07 15:25:31 volumio volumio[906]: info: CoreCommandRouter::volumioPushState Jul 07 15:25:31 volumio volumio[906]: info: MRS: Pushing multiroomSync output update for this device Jul 07 15:25:31 volumio volumio[906]: info: MRS: Pushing multiroomSync output Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 07 15:25:42 volumio volumio[906]: info: Retrieving Cloud Streaming UI Jul 07 15:25:42 volumio volumio[906]: info: Getting Tidal Cloud Configuration Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 07 15:25:42 volumio volumio[906]: info: Getting Qobuz Cloud Configuration Jul 07 15:25:42 volumio volumio[906]: info: Asking plugin for UI Config Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 07 15:25:42 volumio volumio[906]: info: Getting Spotify Cloud Configuration Jul 07 15:25:42 volumio volumio[906]: info: Asking plugin for UI Config Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 07 15:25:42 volumio volumio[906]: info: Saving Spotify Acccount Jul 07 15:25:42 volumio volumio[906]: info: Got it Jul 07 15:25:42 volumio volumio[906]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 07 15:25:42 volumio volumio[906]: info: Got Tidal Cloud Configuration Jul 07 15:25:42 volumio volumio[906]: info: Got it Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::volumioGetBrowseSources Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::volumioGetBrowseSources Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::volumioGetBrowseSources Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 07 15:25:42 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 07 15:25:46 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 07 15:25:50 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 07 15:25:51 volumio volumio[906]: info: Disabling MyMusic plugin upnp Jul 07 15:25:51 volumio sudo[12941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jul 07 15:25:51 volumio sudo[12941]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 07 15:25:51 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Jul 07 15:25:51 volumio volumio[906]: error: Upnp client error: Error: This socket has been ended by the other party Jul 07 15:25:51 volumio volumio[906]: ------------------------------------ BT MESSAGE: BT STATUS: running Jul 07 15:25:52 volumio volumio[906]: info: Enabling MyMusic plugin upnp Jul 07 15:25:52 volumio volumio[906]: info: Enabling plugin upnp Jul 07 15:25:52 volumio volumio[906]: info: Loading plugin "upnp"... Jul 07 15:25:52 volumio volumio[906]: info: [1720362352435] Starting Upmpd Daemon Jul 07 15:25:52 volumio volumio[906]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 07 15:25:52 volumio volumio[906]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 07 15:25:52 volumio volumio[906]: Error: listen EADDRINUSE: address already in use :::6599 Jul 07 15:25:52 volumio volumio[906]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Jul 07 15:25:52 volumio volumio[906]: at listenInCluster (net.js:1366:12) Jul 07 15:25:52 volumio volumio[906]: at Server.listen (net.js:1452:7) Jul 07 15:25:52 volumio volumio[906]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jul 07 15:25:52 volumio volumio[906]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jul 07 15:25:52 volumio volumio[906]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jul 07 15:25:52 volumio volumio[906]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jul 07 15:25:52 volumio volumio[906]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Jul 07 15:25:52 volumio volumio[906]: code: 'EADDRINUSE', Jul 07 15:25:52 volumio volumio[906]: errno: -98, Jul 07 15:25:52 volumio volumio[906]: syscall: 'listen', Jul 07 15:25:52 volumio volumio[906]: address: '::', Jul 07 15:25:52 volumio volumio[906]: port: 6599 Jul 07 15:25:52 volumio volumio[906]: } Jul 07 15:25:52 volumio volumio[906]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 07 15:25:52 volumio sudo[12952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-07 15:24 Jul 07 15:25:52 volumio sudo[12952]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"