Feb 26 16:54:03 volumio vtcs[2313]: [2026-02-26 16:54:03.511] [tisoc] [warning] [operation_curl.cpp:163] Timeout Feb 26 16:54:15 volumio vtcs[2313]: [2026-02-26 16:54:15.525] [tisoc] [warning] [operation_curl.cpp:163] Timeout Feb 26 16:54:27 volumio vtcs[2313]: [2026-02-26 16:54:27.544] [tisoc] [warning] [operation_curl.cpp:163] Timeout Feb 26 16:54:28 volumio go-librespot[1992]: time="2026-02-26T16:54:28+02:00" level=trace msg="sent dealer ping" Feb 26 16:54:28 volumio go-librespot[1992]: time="2026-02-26T16:54:28+02:00" level=trace msg="received dealer pong" Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioNext Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::next Feb 26 16:54:31 volumio volumio[1766]: info: Received next Feb 26 16:54:31 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:31 volumio vtcs[2313]: [feedThread:276] Exiting Feb 26 16:54:31 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:31 volumio volumio[1766]: info: Pushing metadata Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.568+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=43930 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.568+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.581+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.581+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.582+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.582+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:31 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:31 volumio volumio[1766]: info: Pushing metadata Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:31 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:31 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.771+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.771+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.771+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.771+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.772+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.772+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.773+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.773+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.773+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:31 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:31.773+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:32 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:32 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:32 volumio vtcs[2313]: [open:50] Opening with sample rate: 44100, type: 0 Feb 26 16:54:32 volumio vtcs[2313]: [start:106] Entering Feb 26 16:54:32 volumio vtcs[2313]: [start:113] Reopening PCM device... Feb 26 16:54:32 volumio vtcs[2313]: [start:115] PCM opened successfully. Feb 26 16:54:32 volumio vtcs[2313]: [start:120] Exiting Feb 26 16:54:32 volumio vtcs[2313]: [feedThread:223] Entering Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:32 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:32 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:32 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:32 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:32.078+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:32 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:32.079+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:32 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:32 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:32 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:32 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:32.090+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:32 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:32.091+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:32 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:32 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:32 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:32 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:32 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:32.453+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=524 volume=100 Feb 26 16:54:32 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:32.453+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title="Tarp Geltonų Rūtų" Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioNext Feb 26 16:54:37 volumio volumio[1766]: info: CoreStateMachine::next Feb 26 16:54:37 volumio volumio[1766]: info: Received next Feb 26 16:54:37 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:37 volumio vtcs[2313]: [feedThread:276] Exiting Feb 26 16:54:37 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:37 volumio volumio[1766]: info: Pushing metadata Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:37 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:37 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:37 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:37 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:37 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:37 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:37 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:37 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:37 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:37 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:37 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:37.904+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=5647 volume=100 Feb 26 16:54:37 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:37.904+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:37 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:37.905+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:37 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:37.905+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:37 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:37.906+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:37 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:37.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:38 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:38 volumio volumio[1766]: info: Pushing metadata Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.324+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.325+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.342+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.342+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.342+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.342+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.343+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.343+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.344+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.344+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:38 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:38 volumio vtcs[2313]: [open:50] Opening with sample rate: 44100, type: 0 Feb 26 16:54:38 volumio vtcs[2313]: [start:106] Entering Feb 26 16:54:38 volumio vtcs[2313]: [start:113] Reopening PCM device... Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio vtcs[2313]: [start:115] PCM opened successfully. Feb 26 16:54:38 volumio vtcs[2313]: [start:120] Exiting Feb 26 16:54:38 volumio vtcs[2313]: [feedThread:223] Entering Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.595+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.595+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.606+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.607+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:38 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:38 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.976+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=524 volume=100 Feb 26 16:54:38 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:38.976+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title=Apžavai Feb 26 16:54:46 volumio go-librespot[1992]: time="2026-02-26T16:54:46+02:00" level=trace msg="received accesspoint ping" Feb 26 16:54:46 volumio go-librespot[1992]: time="2026-02-26T16:54:46+02:00" level=trace msg="received accesspoint pong ack" Feb 26 16:54:47 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::ClearQueue Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::stop Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::serviceStop Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::serviceStop Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::clearPlayQueue Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::saveQueue Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::addQueueItems Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::addQueueItems Feb 26 16:54:47 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/44792178 Feb 26 16:54:47 volumio volumio[1766]: info: Exploding uri tidal://song/44792178 in service tidal Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/83786196 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/83786196 Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/105048155 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/105048155 Feb 26 16:54:47 volumio vtcs[2313]: [close:85] Entering Feb 26 16:54:47 volumio volumio[1766]: info: PlaybackInactive Feb 26 16:54:47 volumio volumio[1766]: info: Device Session is_active: true Feb 26 16:54:47 volumio volumio[1766]: info: DeviceInactive Feb 26 16:54:47 volumio volumio[1766]: info: Relinquishing Volumio State Feb 26 16:54:47 volumio volumio[1766]: verbose: UNSET VOLATILE: Service: tidalconnect Feb 26 16:54:47 volumio volumio[1766]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Feb 26 16:54:47 volumio volumio[1766]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Feb 26 16:54:47 volumio volumio[1766]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Feb 26 16:54:47 volumio volumio[1766]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::resetVolumioState Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::getcurrentVolume Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioRetrievevolume Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 0 Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:47 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:47 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 0 Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioStop Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::stop Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:47 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:47.296+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:54:47 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:47.296+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id= title= Feb 26 16:54:47 volumio vtcs[2313]: [2026-02-26 16:54:47] [info] asio async_shutdown error: asio.misc:2 (End of file) Feb 26 16:54:47 volumio vtcs[2313]: [feedThread:276] Exiting Feb 26 16:54:47 volumio vtcs[2313]: [close:100] Exiting Feb 26 16:54:47 volumio volumio[1766]: info: explodeTIDALUri took 360 milliseconds Feb 26 16:54:47 volumio volumio[1766]: error: TIDAL Browse Error: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [44792178] not found"} Feb 26 16:54:47 volumio volumio[1766]: error: Commandrouter: Cannot explode uri tidal://song/44792178 from service tidal: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [44792178] not found"} Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::saveQueue Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 0 Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPlay Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::play index 2 Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::addQueueItems Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::addQueueItems Feb 26 16:54:47 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/105048158 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/105048158 Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/6646592 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/6646592 Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/95421560 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/95421560 Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/250615279 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/250615279 Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/250615285 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/250615285 Feb 26 16:54:47 volumio volumio[1766]: info: Adding Item to queue: tidal://song/336709319 Feb 26 16:54:47 volumio volumio[1766]: info: Using cached record of: tidal://song/336709319 Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::stop Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::saveQueue Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::play index undefined Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::startPlaybackTimer Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:47 volumio volumio[1766]: info: [1772117687651] ControllerTidal::clearAddPlayTrack Feb 26 16:54:47 volumio volumio[1766]: info: Getting stream with soundQuality LOSSLESS Feb 26 16:54:47 volumio volumio[1766]: info: getStreamUrl took 205 milliseconds Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand stop took 1 milliseconds Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 16:54:47 volumio volumio[1766]: info: Feb 26 16:54:47 volumio volumio[1766]: ---------------------------- MPD announces system playlist update Feb 26 16:54:47 volumio volumio[1766]: info: Ignoring MPD Status Update Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand clear took 1 milliseconds Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==" Feb 26 16:54:47 volumio volumio[1766]: error: updateQueue error: null Feb 26 16:54:47 volumio volumio[1766]: info: Feb 26 16:54:47 volumio volumio[1766]: ---------------------------- MPD announces system playlist update Feb 26 16:54:47 volumio volumio[1766]: info: Ignoring MPD Status Update Feb 26 16:54:47 volumio volumio[1766]: info: ------------------------------ 2ms Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==" took 1 milliseconds Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand play Feb 26 16:54:47 volumio volumio[1766]: info: ------------------------------ 1ms Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand play took 1 milliseconds Feb 26 16:54:47 volumio volumio[1766]: info: Feb 26 16:54:47 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:54:47 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:54:47 volumio volumio[1766]: info: Feb 26 16:54:47 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand status took 6 milliseconds Feb 26 16:54:47 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand status took 1 milliseconds Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:54:47 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:47 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":311,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","trackType":"tidal"} Feb 26 16:54:47 volumio volumio[1766]: verbose: CURRENT POSITION 2 Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus stop Feb 26 16:54:47 volumio volumio[1766]: info: ------------------------------ 10ms Feb 26 16:54:47 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 26 16:54:47 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:54:47 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:47 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:47 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":311,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","trackType":"tidal"} Feb 26 16:54:47 volumio volumio[1766]: verbose: CURRENT POSITION 2 Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus play Feb 26 16:54:47 volumio volumio[1766]: info: Received an update from plugin. extracting info from payload Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:47 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:47 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:47 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:47 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:47 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:47 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:47 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:47.959+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:47 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:47.960+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/105048158 title="I Can't Tell You Why" Feb 26 16:54:47 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:47.960+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:47 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:47.960+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/105048158 title="I Can't Tell You Why" Feb 26 16:54:47 volumio volumio[1766]: info: ------------------------------ 10ms Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioNext Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::next Feb 26 16:54:50 volumio volumio[1766]: info: [1772117690091] ControllerTidal::next Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::next Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::stop Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::serviceStop Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::serviceStop Feb 26 16:54:50 volumio volumio[1766]: info: [1772117690093] ControllerTidal::stop Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::stop Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.095+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.095+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/105048158 title="I Can't Tell You Why" Feb 26 16:54:50 volumio volumio[1766]: info: Feb 26 16:54:50 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand stop took 5 milliseconds Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::play index undefined Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::startPlaybackTimer Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: info: [1772117690099] ControllerTidal::clearAddPlayTrack Feb 26 16:54:50 volumio volumio[1766]: info: Getting stream with soundQuality LOSSLESS Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand status took 2 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.106+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.106+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:54:50 volumio volumio[1766]: info: ------------------------------ 7ms Feb 26 16:54:50 volumio volumio[1766]: info: getStreamUrl took 192 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand stop took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 16:54:50 volumio volumio[1766]: info: Feb 26 16:54:50 volumio volumio[1766]: ---------------------------- MPD announces system playlist update Feb 26 16:54:50 volumio volumio[1766]: info: Ignoring MPD Status Update Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand clear took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxMTE1MjVhZWQ1ZTliMDM4YzY1N2RjYjZjYWUxMDdhYS5tcDQ/0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==" Feb 26 16:54:50 volumio volumio[1766]: error: updateQueue error: null Feb 26 16:54:50 volumio volumio[1766]: info: ------------------------------ 0ms Feb 26 16:54:50 volumio volumio[1766]: info: Feb 26 16:54:50 volumio volumio[1766]: ---------------------------- MPD announces system playlist update Feb 26 16:54:50 volumio volumio[1766]: info: Ignoring MPD Status Update Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxMTE1MjVhZWQ1ZTliMDM4YzY1N2RjYjZjYWUxMDdhYS5tcDQ/0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==" took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand play Feb 26 16:54:50 volumio volumio[1766]: info: ------------------------------ 1ms Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand play took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: info: Feb 26 16:54:50 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:54:50 volumio volumio[1766]: info: Feb 26 16:54:50 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand status took 1 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand status took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":186,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxMTE1MjVhZWQ1ZTliMDM4YzY1N2RjYjZjYWUxMDdhYS5tcDQ/0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","trackType":"tidal"} Feb 26 16:54:50 volumio volumio[1766]: verbose: CURRENT POSITION 3 Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus stop Feb 26 16:54:50 volumio volumio[1766]: info: ------------------------------ 2ms Feb 26 16:54:50 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:54:50 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:54:50 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:50 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:50 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":186,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxMTE1MjVhZWQ1ZTliMDM4YzY1N2RjYjZjYWUxMDdhYS5tcDQ/0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","trackType":"tidal"} Feb 26 16:54:50 volumio volumio[1766]: verbose: CURRENT POSITION 3 Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus play Feb 26 16:54:50 volumio volumio[1766]: info: Received an update from plugin. extracting info from payload Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:50 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:50 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:50 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.380+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.380+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.380+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:54:50 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:50.380+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:54:50 volumio volumio[1766]: info: ------------------------------ 9ms Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::volumioPrevious Feb 26 16:54:53 volumio volumio[1766]: info: CoreStateMachine::previous Feb 26 16:54:53 volumio volumio[1766]: info: [1772117693486] ControllerTidal::seek Feb 26 16:54:53 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 16:54:53 volumio volumio[1766]: info: ControllerMpd::seek Feb 26 16:54:53 volumio volumio[1766]: error: null Feb 26 16:54:53 volumio volumio[1766]: info: Feb 26 16:54:53 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:54:53 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:54:53 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:54:53 volumio volumio[1766]: info: sendMpdCommand status took 0 milliseconds Feb 26 16:54:53 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:54:53 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:54:53 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 16:54:53 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:54:53 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:54:53 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:54:53 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":186,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"778 Kbps","isStreaming":false,"title":"0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxMTE1MjVhZWQ1ZTliMDM4YzY1N2RjYjZjYWUxMDdhYS5tcDQ/0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","trackType":"tidal"} Feb 26 16:54:53 volumio volumio[1766]: verbose: CURRENT POSITION 3 Feb 26 16:54:53 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:54:53 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus play Feb 26 16:54:53 volumio volumio[1766]: info: Received an update from plugin. extracting info from payload Feb 26 16:54:53 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:53 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:53 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:53 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:54:53 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:54:53 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:54:53 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:54:53 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:53.495+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:53 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:53.495+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:54:53 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:53.495+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:54:53 volumio volumio5-onboarding[2329]: time=2026-02-26T16:54:53.496+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:54:53 volumio volumio[1766]: info: ------------------------------ 7ms Feb 26 16:54:58 volumio go-librespot[1992]: time="2026-02-26T16:54:58+02:00" level=trace msg="sent dealer ping" Feb 26 16:54:58 volumio go-librespot[1992]: time="2026-02-26T16:54:58+02:00" level=trace msg="received dealer pong" Feb 26 16:55:02 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::ClearQueue Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::stop Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::serviceStop Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::serviceStop Feb 26 16:55:02 volumio volumio[1766]: info: [1772117702251] ControllerTidal::stop Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::stop Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::clearPlayQueue Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::saveQueue Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::addQueueItems Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::addQueueItems Feb 26 16:55:02 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/44792178 Feb 26 16:55:02 volumio volumio[1766]: info: Exploding uri tidal://song/44792178 in service tidal Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/83786196 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/83786196 Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/105048155 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/105048155 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.253+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.253+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:55:02 volumio volumio[1766]: info: Feb 26 16:55:02 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand stop took 10 milliseconds Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand status took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 3 Feb 26 16:55:02 volumio volumio[1766]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxMTE1MjVhZWQ1ZTliMDM4YzY1N2RjYjZjYWUxMDdhYS5tcDQ/0.flac?token=1772121290~M2MyOWY3MjBlMzNiMzNhZGE1NTE4NWZhMDVjNGZiMzUwODQ4ZDA1Mw==","trackType":"tidal"} Feb 26 16:55:02 volumio volumio[1766]: verbose: CURRENT POSITION 3 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::syncState stateService stop Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus stop Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio[1766]: info: No code Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.270+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.270+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.270+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.270+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.271+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.271+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/6646592 title="Big Love (Live at Warner Brothers Studios in Burbank, CA 5/23/97)" Feb 26 16:55:02 volumio volumio[1766]: info: ------------------------------ 10ms Feb 26 16:55:02 volumio volumio[1766]: info: explodeTIDALUri took 389 milliseconds Feb 26 16:55:02 volumio volumio[1766]: error: TIDAL Browse Error: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [44792178] not found"} Feb 26 16:55:02 volumio volumio[1766]: error: Commandrouter: Cannot explode uri tidal://song/44792178 from service tidal: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [44792178] not found"} Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::saveQueue Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPlay Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::play index 2 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::addQueueItems Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::addQueueItems Feb 26 16:55:02 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/105048158 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/105048158 Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/6646592 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/6646592 Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/95421560 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/95421560 Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/250615279 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/250615279 Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/250615285 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/250615285 Feb 26 16:55:02 volumio volumio[1766]: info: Adding Item to queue: tidal://song/336709319 Feb 26 16:55:02 volumio volumio[1766]: info: Using cached record of: tidal://song/336709319 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::stop Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::saveQueue Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::play index undefined Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::updateTrackBlock Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrackBlock Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::startPlaybackTimer Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:55:02 volumio volumio[1766]: info: [1772117702647] ControllerTidal::clearAddPlayTrack Feb 26 16:55:02 volumio volumio[1766]: info: Getting stream with soundQuality LOSSLESS Feb 26 16:55:02 volumio volumio[1766]: info: getStreamUrl took 182 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand stop took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 16:55:02 volumio volumio[1766]: info: Feb 26 16:55:02 volumio volumio[1766]: ---------------------------- MPD announces system playlist update Feb 26 16:55:02 volumio volumio[1766]: info: Ignoring MPD Status Update Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand clear took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==" Feb 26 16:55:02 volumio volumio[1766]: error: updateQueue error: null Feb 26 16:55:02 volumio volumio[1766]: info: ------------------------------ 0ms Feb 26 16:55:02 volumio volumio[1766]: info: Feb 26 16:55:02 volumio volumio[1766]: ---------------------------- MPD announces system playlist update Feb 26 16:55:02 volumio volumio[1766]: info: Ignoring MPD Status Update Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==" took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand play Feb 26 16:55:02 volumio volumio[1766]: info: ------------------------------ 1ms Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand play took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: info: Feb 26 16:55:02 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:55:02 volumio volumio[1766]: info: Feb 26 16:55:02 volumio volumio[1766]: ---------------------------- MPD announces state update: player Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand status took 1 milliseconds Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::getState Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand status took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::parseState Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:55:02 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":311,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","trackType":"tidal"} Feb 26 16:55:02 volumio volumio[1766]: verbose: CURRENT POSITION 2 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus stop Feb 26 16:55:02 volumio volumio[1766]: info: ------------------------------ 3ms Feb 26 16:55:02 volumio volumio[1766]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:55:02 volumio volumio[1766]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:55:02 volumio volumio[1766]: info: ControllerMpd::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::servicePushState Feb 26 16:55:02 volumio volumio[1766]: info: CorePlayQueue::getTrack 2 Feb 26 16:55:02 volumio volumio[1766]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":311,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidhNDFjZGQ4MWFkMDlhYzg0NTgyZTUyOGY5ZTg3ODU0Nl82MS5tcDQ/0.flac?token=1772121287~Mzk4Nzk2ZWJhYzY0NmFmMDA1OGRkYjNlMmZlMGIzNzM3Y2NjOWVkMg==","trackType":"tidal"} Feb 26 16:55:02 volumio volumio[1766]: verbose: CURRENT POSITION 2 Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::syncState stateService play Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::syncState currentStatus play Feb 26 16:55:02 volumio volumio[1766]: info: Received an update from plugin. extracting info from payload Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio[1766]: info: CoreStateMachine::pushState Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioPushState Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output update for this device Feb 26 16:55:02 volumio volumio[1766]: info: MRS: Pushing multiroomSync output Feb 26 16:55:02 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.883+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.883+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/105048158 title="I Can't Tell You Why" Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.883+02:00 level=INFO msg="emitting player state changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:55:02 volumio volumio5-onboarding[2329]: time=2026-02-26T16:55:02.883+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.222.135.177:35704 @ 0x174c990" id=tidal://song/105048158 title="I Can't Tell You Why" Feb 26 16:55:02 volumio volumio[1766]: info: ------------------------------ 6ms Feb 26 16:55:08 volumio volumio[1766]: info: Tunnel connection is inactive, restarting it Feb 26 16:55:08 volumio volumio[1766]: info: Starting Tunnel 1 Feb 26 16:55:08 volumio volumio[1766]: info: Starting Tunnel Connection Checker Feb 26 16:55:08 volumio sudo[5842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Feb 26 16:55:08 volumio sudo[5842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 26 16:55:08 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:08 volumio sudo[5842]: pam_unix(sudo:session): session closed for user root Feb 26 16:55:08 volumio volumio[1766]: info: Remote SSH Started Feb 26 16:55:08 volumio autossh[5845]: port set to 0, monitoring disabled Feb 26 16:55:08 volumio autossh[5845]: starting ssh (count 1) Feb 26 16:55:08 volumio autossh[5845]: ssh child pid is 5848 Feb 26 16:55:08 volumio volumio[1766]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 26 16:55:08 volumio volumio[1766]: info: CoreCommandRouter::volumioGetState Feb 26 16:55:08 volumio volumiossh-tunnel[5848]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Feb 26 16:55:08 volumio autossh[5845]: ssh exited prematurely with status 255; autossh exiting Feb 26 16:55:08 volumio systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:55:08 volumio systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Feb 26 16:55:08 volumio systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 1. Feb 26 16:55:08 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:08 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:08 volumio autossh[5850]: port set to 0, monitoring disabled Feb 26 16:55:08 volumio autossh[5850]: starting ssh (count 1) Feb 26 16:55:08 volumio autossh[5850]: ssh child pid is 5853 Feb 26 16:55:08 volumio volumiossh-tunnel[5853]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Feb 26 16:55:08 volumio autossh[5850]: ssh exited prematurely with status 255; autossh exiting Feb 26 16:55:08 volumio systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:55:08 volumio systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 2. Feb 26 16:55:09 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:09 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:09 volumio autossh[5855]: port set to 0, monitoring disabled Feb 26 16:55:09 volumio autossh[5855]: starting ssh (count 1) Feb 26 16:55:09 volumio autossh[5855]: ssh child pid is 5858 Feb 26 16:55:09 volumio volumiossh-tunnel[5858]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Feb 26 16:55:09 volumio autossh[5855]: ssh exited prematurely with status 255; autossh exiting Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 3. Feb 26 16:55:09 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:09 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:09 volumio autossh[5860]: port set to 0, monitoring disabled Feb 26 16:55:09 volumio autossh[5860]: starting ssh (count 1) Feb 26 16:55:09 volumio autossh[5860]: ssh child pid is 5863 Feb 26 16:55:09 volumio volumiossh-tunnel[5863]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Feb 26 16:55:09 volumio autossh[5860]: ssh exited prematurely with status 255; autossh exiting Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 4. Feb 26 16:55:09 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:09 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:09 volumio autossh[5865]: port set to 0, monitoring disabled Feb 26 16:55:09 volumio autossh[5865]: starting ssh (count 1) Feb 26 16:55:09 volumio autossh[5865]: ssh child pid is 5868 Feb 26 16:55:09 volumio volumiossh-tunnel[5868]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Feb 26 16:55:09 volumio autossh[5865]: ssh exited prematurely with status 255; autossh exiting Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:55:09 volumio systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Feb 26 16:55:10 volumio systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 5. Feb 26 16:55:10 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:10 volumio systemd[1]: sshtunnel.service: Start request repeated too quickly. Feb 26 16:55:10 volumio systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Feb 26 16:55:10 volumio systemd[1]: Failed to start sshtunnel.service - MyVolumio SSH Tunnel. Feb 26 16:55:20 volumio volumio[1766]: Searching plugin music_service/tidal Feb 26 16:55:20 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 26 16:55:21 volumio volumio[1766]: info: searchTIDALUri took 568 milliseconds Feb 26 16:55:21 volumio volumio[1766]: info: search took 569 milliseconds Feb 26 16:55:21 volumio volumio[1766]: info: All search sources collected, pushing search results Feb 26 16:55:22 volumio volumio[1766]: Searching plugin music_service/tidal Feb 26 16:55:22 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 26 16:55:23 volumio volumio[1766]: info: searchTIDALUri took 381 milliseconds Feb 26 16:55:23 volumio volumio[1766]: info: search took 382 milliseconds Feb 26 16:55:23 volumio volumio[1766]: info: All search sources collected, pushing search results Feb 26 16:55:25 volumio volumio[1766]: Searching plugin music_service/tidal Feb 26 16:55:25 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 26 16:55:26 volumio volumio[1766]: info: searchTIDALUri took 403 milliseconds Feb 26 16:55:26 volumio volumio[1766]: info: search took 403 milliseconds Feb 26 16:55:26 volumio volumio[1766]: info: All search sources collected, pushing search results Feb 26 16:55:27 volumio volumio[1766]: Searching plugin music_service/tidal Feb 26 16:55:27 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 26 16:55:27 volumio volumio[1766]: info: searchTIDALUri took 261 milliseconds Feb 26 16:55:27 volumio volumio[1766]: info: search took 262 milliseconds Feb 26 16:55:27 volumio volumio[1766]: info: All search sources collected, pushing search results Feb 26 16:55:28 volumio go-librespot[1992]: time="2026-02-26T16:55:28+02:00" level=trace msg="sent dealer ping" Feb 26 16:55:28 volumio go-librespot[1992]: time="2026-02-26T16:55:28+02:00" level=trace msg="received dealer pong" Feb 26 16:55:31 volumio volumio[1766]: Searching plugin music_service/tidal Feb 26 16:55:31 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 26 16:55:31 volumio volumio[1766]: info: searchTIDALUri took 358 milliseconds Feb 26 16:55:31 volumio volumio[1766]: info: search took 359 milliseconds Feb 26 16:55:31 volumio volumio[1766]: info: All search sources collected, pushing search results Feb 26 16:55:39 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 26 16:55:40 volumio volumio[1766]: info: browseTIDALUri took 1020 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:55:40 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:55:40 volumio volumio[1766]: info: Preload queue cleared Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/397410961 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/137191025 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/381227644 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/475988154 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/448672438 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/295423142 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/310884942 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/269066123 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/128797819 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/257754516 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/153619783 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/145978527 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/236284913 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/221893249 Feb 26 16:55:40 volumio volumio[1766]: info: Preloading song: tidal://song/209676654 Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/397410961 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Executing endpoint getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: Executing endpoint getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/137191025 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Executing endpoint getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: Executing endpoint getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: Executing endpoint getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/381227644 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Executing endpoint metavolumio Feb 26 16:55:40 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/475988154 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 224 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/448672438 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/295423142 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/310884942 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/269066123 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 281 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 330 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 166 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/128797819 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/257754516 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 307 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/153619783 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 289 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/145978527 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 171 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 278 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/236284913 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 173 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 285 milliseconds Feb 26 16:55:40 volumio volumio[1766]: info: Exploding uri tidal://song/221893249 in service tidal Feb 26 16:55:40 volumio volumio[1766]: info: explodeTIDALUri took 169 milliseconds Feb 26 16:55:41 volumio volumio[1766]: info: Exploding uri tidal://song/209676654 in service tidal Feb 26 16:55:41 volumio volumio[1766]: info: explodeTIDALUri took 169 milliseconds Feb 26 16:55:41 volumio volumio[1766]: info: explodeTIDALUri took 180 milliseconds Feb 26 16:55:41 volumio volumio[1766]: info: explodeTIDALUri took 170 milliseconds Feb 26 16:55:41 volumio volumio[1766]: info: Executing endpoint metavolumio Feb 26 16:55:41 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 16:55:41 volumio volumio[1766]: info: explodeTIDALUri took 174 milliseconds Feb 26 16:55:41 volumio volumio[1766]: info: Executing endpoint metavolumio Feb 26 16:55:41 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 16:55:41 volumio volumio[1766]: info: Executing endpoint metavolumio Feb 26 16:55:41 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 16:55:41 volumio volumio[1766]: info: Executing endpoint metavolumio Feb 26 16:55:41 volumio volumio[1766]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 26 16:55:44 volumio volumio[1766]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 16:55:44 volumio volumio[1766]: TypeError: Cannot read properties of null (reading 'slice') Feb 26 16:55:44 volumio volumio[1766]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 26 16:55:44 volumio volumio[1766]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 26 16:55:44 volumio volumio[1766]: at Object.onceWrapper (node:events:629:26) Feb 26 16:55:44 volumio volumio[1766]: at ClientRequest.emit (node:events:514:28) Feb 26 16:55:44 volumio volumio[1766]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 26 16:55:44 volumio volumio[1766]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 26 16:55:44 volumio volumio[1766]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 26 16:55:44 volumio volumio[1766]: at TLSSocket.emit (node:events:514:28) Feb 26 16:55:44 volumio volumio[1766]: at addChunk (node:internal/streams/readable:343:12) Feb 26 16:55:44 volumio volumio[1766]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 26 16:55:44 volumio volumio[1766]: at Readable.push (node:internal/streams/readable:253:10) Feb 26 16:55:44 volumio volumio[1766]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Feb 26 16:55:44 volumio volumio[1766]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 16:55:44 volumio sudo[5943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 16:54' Feb 26 16:55:44 volumio sudo[5943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"