-- Logs begin at Sat 2026-05-30 18:50:40 CEST, end at Sun 2026-05-31 17:55:08 CEST. -- May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.342+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=12.404423ms timeout=3s volume=91 May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:01 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.369+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=8984 volume=91 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.369+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=8984 volume=91 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.370+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.370+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:01 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:01 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.459+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=8984 volume=91 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.459+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=8984 volume=91 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.460+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.460+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:01 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.537+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=9.332429ms timeout=3s volume=81 May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:01 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.561+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=9234 volume=81 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.561+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=9234 volume=81 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.562+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.562+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:01 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:01 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.596+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=9234 volume=81 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.597+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=9234 volume=81 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.597+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.597+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:01 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.632+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=4.81822ms timeout=3s volume=76 May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:01 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.646+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=9234 volume=76 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.647+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=9234 volume=76 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.647+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.648+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:01 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:01 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:01 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:01 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.752+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=9234 volume=76 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.753+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=9234 volume=76 May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.753+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:01.754+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:01 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:01 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.395+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=5.260405ms timeout=3s volume=81 May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:02 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.407+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=10001 volume=81 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.408+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=10001 volume=81 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.408+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.409+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:02 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:02 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.494+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=10001 volume=81 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.495+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=10001 volume=81 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.495+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.496+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:02 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.596+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=4.580387ms timeout=3s volume=91 May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:02 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.618+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=10252 volume=91 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.619+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=10252 volume=91 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.619+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.619+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:02 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:02 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.659+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=10252 volume=91 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.659+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=10252 volume=91 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.660+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.660+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:02 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.701+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=13.513252ms timeout=3s volume=105 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.701+02:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=13.513252ms timeout=3s volume=105 error="could not set volume to 105: volume must be between 0 and 100, got 105" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.795+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=7.181704ms timeout=3s volume=105 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.795+02:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=7.181704ms timeout=3s volume=105 error="could not set volume to 105: volume must be between 0 and 100, got 105" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.912+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=21.410842ms timeout=3s volume=96 May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:02 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.937+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=10502 volume=96 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.938+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=10502 volume=96 May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.938+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:02.939+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:02 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:02 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:02 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:02 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:02 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:03 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:03.000+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=10502 volume=96 May 31 17:54:03 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:03.001+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=10502 volume=96 May 31 17:54:03 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:03.001+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:03 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:03.002+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:03 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:03 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:05 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:05 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:05 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:05 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:05 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:05 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:05 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.640+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=13258 volume=100 May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.641+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=13258 volume=100 May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.641+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.642+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:05 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:05 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:05 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:05 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:05 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:05 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:05 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.728+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=13258 volume=100 May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.729+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=13258 volume=100 May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.729+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:05 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:05.730+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:05 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:05 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.373+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=31.369457ms timeout=3s volume=95 May 31 17:54:07 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:07 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:07 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:07 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:07 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:07 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:07 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.397+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=15013 volume=95 May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.397+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=15013 volume=95 May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.398+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.398+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:07 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:07 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:07 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:07 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:07 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:07 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:07 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.512+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=15013 volume=95 May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.512+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=15013 volume=95 May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.513+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:07 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:07.513+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:07 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:07 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.115+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=4.934176ms timeout=3s volume=91 May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:08 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.128+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=15771 volume=91 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.129+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=15771 volume=91 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.129+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.130+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:08 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:08 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.218+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=15771 volume=91 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.218+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=15771 volume=91 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.219+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.219+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:08 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.331+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=22.293602ms timeout=3s volume=81 May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:08 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.351+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=16020 volume=81 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.352+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=16020 volume=81 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.352+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.353+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:08 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:08 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.389+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=16020 volume=81 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.389+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=16020 volume=81 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.390+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.390+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:08 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.413+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=2.912291ms timeout=3s volume=76 May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:08 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.447+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=16020 volume=76 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.448+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=16020 volume=76 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.448+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.449+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:08 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:08 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:08 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:08 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.537+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=16020 volume=76 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.537+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=16020 volume=76 May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.538+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:08.538+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:08 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:08 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.176+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=12.17841ms timeout=3s volume=81 May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:12 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.194+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=19787 volume=81 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.194+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=19787 volume=81 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.195+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.195+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:12 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:12 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.277+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=19787 volume=81 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.278+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=19787 volume=81 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.278+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.278+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:12 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.686+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=8.815546ms timeout=3s volume=91 May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:12 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.699+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=20289 volume=91 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.700+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=20289 volume=91 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.700+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.701+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:12 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:12 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.731+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=20289 volume=91 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.732+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=20289 volume=91 May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.732+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.733+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:12 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:12 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:12 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:12.989+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=14.47199ms timeout=3s volume=100 May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:12 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:12 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:12 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:13 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.003+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=20539 volume=100 May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.003+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=20539 volume=100 May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.004+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.004+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:13 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:13 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:13 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:13 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:13 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:13 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:13 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:13 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.085+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=20789 volume=100 May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.085+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=20789 volume=100 May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.086+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:13 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:13.086+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:13 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:13 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.410+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=8.422022ms timeout=3s volume=95 May 31 17:54:15 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:15 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:15 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:15 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:15 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:15 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:15 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.423+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=23042 volume=95 May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.424+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=23042 volume=95 May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.424+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.425+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:15 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:15 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:15 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:15 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:15 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:15 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:15 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.505+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=23042 volume=95 May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.505+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=23042 volume=95 May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.506+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:15 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:15.506+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:15 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:15 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:23 primo volumio[3513]: info: CoreCommandRouter::volumioSeek May 31 17:54:23 primo volumio[3513]: info: CoreStateMachine::seek May 31 17:54:23 primo volumio[3513]: info: CorePlayQueue::getTrack 0 May 31 17:54:23 primo volumio[3513]: info: TRACKBLOCK {"album":"Offramp","albumUri":"tidal://album/13363052","albumart":"https://resources.tidal.com/images/0a35c713/3d70/4233/87c0/eb512c11ce08/640x640.jpg","artist":"Pat Metheny","artistUri":"tidal://artist/14068","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":527,"explicit":false,"name":"Are You Going With Me?","samplerate":"44.1 KHz","service":"tidal","title":"Are You Going With Me?","trackType":"tidal","tracknumber":2,"type":"track","uri":"tidal://song/13363054","volumeNumber":1} May 31 17:54:23 primo volumio[3513]: info: CoreStateMachine::startPlaybackTimer May 31 17:54:23 primo volumio[3513]: info: CorePlayQueue::getTrack 0 May 31 17:54:23 primo volumio[3513]: info: [1780242863929] ControllerTidal::seek May 31 17:54:23 primo volumio[3513]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 17:54:23 primo volumio[3513]: info: ControllerMpd::seek May 31 17:54:23 primo kernel: asoc-aml-card auge_sound: tdm playback stop May 31 17:54:23 primo kernel: spdif_a is set to disable May 31 17:54:23 primo kernel: aml_tdm_prepare(), reset fddr May 31 17:54:23 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 May 31 17:54:23 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 May 31 17:54:23 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 31 17:54:23 primo kernel: tdm playback mute: 0, lane_cnt = 8 May 31 17:54:23 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:23 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:23 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:23 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:23 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:23 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:23 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:23.959+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:23 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:23.960+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:23 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:23.960+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:23 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:23.961+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:23 primo volumio[3513]: error: null May 31 17:54:23 primo volumio[3513]: info: May 31 17:54:23 primo volumio[3513]: ---------------------------- MPD announces state update: player May 31 17:54:23 primo volumio[3513]: info: ControllerMpd::getState May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::sendMpdCommand status May 31 17:54:23 primo volumio[3513]: info: May 31 17:54:23 primo volumio[3513]: ---------------------------- MPD announces state update: player May 31 17:54:23 primo volumio[3513]: info: ControllerMpd::getState May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::sendMpdCommand status May 31 17:54:23 primo volumio[3513]: info: May 31 17:54:23 primo volumio[3513]: ---------------------------- MPD announces state update: player May 31 17:54:23 primo volumio[3513]: info: ControllerMpd::getState May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::sendMpdCommand status May 31 17:54:23 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:23 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:23 primo volumio[3513]: info: sendMpdCommand status took 17 milliseconds May 31 17:54:23 primo volumio[3513]: info: sendMpdCommand status took 15 milliseconds May 31 17:54:23 primo volumio[3513]: info: sendMpdCommand status took 14 milliseconds May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::parseState May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::parseState May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::parseState May 31 17:54:23 primo volumio[3513]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 17:54:24 primo volumio[3513]: info: sendMpdCommand playlistinfo took 3 milliseconds May 31 17:54:24 primo volumio[3513]: info: sendMpdCommand playlistinfo took 4 milliseconds May 31 17:54:24 primo volumio[3513]: info: sendMpdCommand playlistinfo took 3 milliseconds May 31 17:54:24 primo volumio[3513]: verbose: ControllerMpd::parseTrackInfo May 31 17:54:24 primo volumio[3513]: info: ControllerMpd::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::servicePushState May 31 17:54:24 primo volumio[3513]: info: CorePlayQueue::getTrack 0 May 31 17:54:24 primo volumio[3513]: verbose: STATE SERVICE {"status":"play","position":0,"seek":121212,"duration":527,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"790 Kbps","isStreaming":false,"title":"13363054&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/13363054&soundQuality=LOSSLESS","trackType":"tidal"} May 31 17:54:24 primo volumio[3513]: verbose: CURRENT POSITION 0 May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::syncState stateService play May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::syncState currentStatus play May 31 17:54:24 primo volumio[3513]: info: Received an update from plugin. extracting info from payload May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:24 primo volumio[3513]: info: ControllerMpd::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::servicePushState May 31 17:54:24 primo volumio[3513]: info: CorePlayQueue::getTrack 0 May 31 17:54:24 primo volumio[3513]: verbose: STATE SERVICE {"status":"play","position":0,"seek":121212,"duration":527,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"790 Kbps","isStreaming":false,"title":"13363054&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/13363054&soundQuality=LOSSLESS","trackType":"tidal"} May 31 17:54:24 primo volumio[3513]: verbose: CURRENT POSITION 0 May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::syncState stateService play May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::syncState currentStatus play May 31 17:54:24 primo volumio[3513]: info: Received an update from plugin. extracting info from payload May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:24 primo volumio[3513]: info: ControllerMpd::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::servicePushState May 31 17:54:24 primo volumio[3513]: info: CorePlayQueue::getTrack 0 May 31 17:54:24 primo volumio[3513]: verbose: STATE SERVICE {"status":"play","position":0,"seek":121212,"duration":527,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"790 Kbps","isStreaming":false,"title":"13363054&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/13363054&soundQuality=LOSSLESS","trackType":"tidal"} May 31 17:54:24 primo volumio[3513]: verbose: CURRENT POSITION 0 May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::syncState stateService play May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::syncState currentStatus play May 31 17:54:24 primo volumio[3513]: info: Received an update from plugin. extracting info from payload May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:24 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:24 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:24 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.044+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.045+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.045+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.045+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.048+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.050+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.050+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.051+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.052+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.052+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.053+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.053+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.053+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.054+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.054+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.055+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.055+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo kernel: asoc-aml-card auge_sound: tdm playback enable May 31 17:54:24 primo kernel: spdif_a is set to enable May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.056+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=120000 volume=95 May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.056+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.057+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:24.058+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:24 primo volumio[3513]: info: ------------------------------ 113ms May 31 17:54:24 primo volumio[3513]: info: ------------------------------ 111ms May 31 17:54:24 primo volumio[3513]: info: ------------------------------ 110ms May 31 17:54:24 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:24 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:24 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:24 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:24 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:24 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:24 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:24 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:24 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:24 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.846+02:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" latency=18.961839ms timeout=3s volume=91 May 31 17:54:30 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 17:54:30 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:30 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 17:54:30 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:30 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:30 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:30 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.865+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=126916 volume=91 May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.865+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=126916 volume=91 May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.866+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.866+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:30 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:30 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:30 primo volumio[3513]: info: CoreStateMachine::pushState May 31 17:54:30 primo volumio[3513]: info: CoreCommandRouter::volumioPushState May 31 17:54:30 primo volumio[3513]: info: CoreCommandRouter::volumioGetState May 31 17:54:30 primo volumio[3513]: info: MRS: Pushing multiroomSync output update for this device May 31 17:54:30 primo volumio[3513]: info: MRS: Pushing multiroomSync output May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.905+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" state=STATUS_PLAYING positionMs=126916 volume=91 May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.906+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" state=STATUS_PLAYING positionMs=126916 volume=91 May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52794,192.168.123.49:52900,00:00:00:00:00:00%0c @ 0x1afe1b0" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:30 primo volumio5-onboarding[3999]: time=2026-05-31T17:54:30.907+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.123.49:52900 @ 0x1801740" id=tidal://song/13363054 title="Are You Going With Me?" May 31 17:54:30 primo volumio[3513]: info: Signalling Playback active due to playback status change May 31 17:54:30 primo volumio[3513]: info: Updating RAAT Signal Path May 31 17:54:50 primo volumio[3513]: Searching all installed plugins May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: , search May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: last_100 , search May 31 17:54:50 primo volumio[3513]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 31 17:54:50 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 31 17:54:51 primo volumio[3513]: info: searchTIDALUri took 542 milliseconds May 31 17:54:51 primo volumio[3513]: info: search took 547 milliseconds May 31 17:54:51 primo volumio[3513]: info: All search sources collected, pushing search results May 31 17:54:51 primo volumio[3513]: Searching all installed plugins May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: , search May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: last_100 , search May 31 17:54:51 primo volumio[3513]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 31 17:54:51 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 31 17:54:52 primo volumio[3513]: info: searchTIDALUri took 372 milliseconds May 31 17:54:52 primo volumio[3513]: info: search took 373 milliseconds May 31 17:54:52 primo volumio[3513]: info: All search sources collected, pushing search results May 31 17:54:55 primo volumio[3513]: Searching all installed plugins May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: , search May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: last_100 , search May 31 17:54:55 primo volumio[3513]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 31 17:54:55 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 31 17:54:55 primo volumio[3513]: info: searchTIDALUri took 299 milliseconds May 31 17:54:55 primo volumio[3513]: info: search took 300 milliseconds May 31 17:54:55 primo volumio[3513]: info: All search sources collected, pushing search results May 31 17:54:58 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri May 31 17:55:00 primo volumio[3513]: info: browseTIDALUri took 2006 milliseconds May 31 17:55:00 primo volumio[3513]: info: Preload queue cleared May 31 17:55:00 primo volumio[3513]: info: Preload queue cleared May 31 17:55:00 primo volumio[3513]: info: Preload queue cleared May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974259 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/13363054 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753589 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974254 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974261 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974249 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974250 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/13353689 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974253 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753593 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974257 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/341894 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753732 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/341892 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753764 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974251 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974252 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974256 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974260 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974255 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753592 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/470269551 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753761 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753656 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/3974258 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753863 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/341893 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/14337740 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753654 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753837 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753657 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753590 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753591 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/13420248 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753683 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753733 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753628 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/2871590 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753595 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753596 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753706 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753731 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/471760904 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753759 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753630 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753864 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753659 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/149753762 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/13497372 May 31 17:55:00 primo volumio[3513]: info: Preloading song: tidal://song/13497379 May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974259 in service tidal May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/13363054 in service tidal May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/149753589 in service tidal May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974254 in service tidal May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974261 in service tidal May 31 17:55:00 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974249 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 259 milliseconds May 31 17:55:00 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974250 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 288 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/13353689 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 265 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974253 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 261 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/149753593 in service tidal May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974257 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 307 milliseconds May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 290 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/341894 in service tidal May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/149753732 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 299 milliseconds May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 261 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/341892 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 274 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/149753764 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 257 milliseconds May 31 17:55:00 primo volumio[3513]: info: Exploding uri tidal://song/3974251 in service tidal May 31 17:55:00 primo volumio[3513]: info: explodeTIDALUri took 270 milliseconds May 31 17:55:01 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/3974252 in service tidal May 31 17:55:01 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 275 milliseconds May 31 17:55:01 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/3974256 in service tidal May 31 17:55:01 primo volumio[3513]: info: Executing endpoint getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 278 milliseconds May 31 17:55:01 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/3974260 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 257 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/3974255 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 263 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753592 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 273 milliseconds May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 243 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/470269551 in service tidal May 31 17:55:01 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 247 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753761 in service tidal May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753656 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 256 milliseconds May 31 17:55:01 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 233 milliseconds May 31 17:55:01 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/3974258 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 239 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753863 in service tidal May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/341893 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 288 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/14337740 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 286 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753654 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 300 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753837 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 292 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753657 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 287 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753590 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 274 milliseconds May 31 17:55:01 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753591 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 274 milliseconds May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 253 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/13420248 in service tidal May 31 17:55:01 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:01 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753683 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 275 milliseconds May 31 17:55:01 primo volumio[3513]: info: Exploding uri tidal://song/149753733 in service tidal May 31 17:55:01 primo volumio[3513]: info: explodeTIDALUri took 276 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753628 in service tidal May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/2871590 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 311 milliseconds May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 284 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753595 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 271 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753596 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 264 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753706 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 260 milliseconds May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 238 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753731 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 241 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/471760904 in service tidal May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753759 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 258 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753630 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 269 milliseconds May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 249 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753864 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 252 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753659 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 251 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/149753762 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 254 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/13497372 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 254 milliseconds May 31 17:55:02 primo volumio[3513]: info: Exploding uri tidal://song/13497379 in service tidal May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 231 milliseconds May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 240 milliseconds May 31 17:55:02 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:02 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 274 milliseconds May 31 17:55:02 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 263 milliseconds May 31 17:55:02 primo volumio[3513]: info: Executing endpoint metavolumio May 31 17:55:02 primo volumio[3513]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 17:55:02 primo volumio[3513]: info: explodeTIDALUri took 239 milliseconds May 31 17:55:05 primo volumio[3513]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Lyle%20Mays/b95d79d7-c3b4-4f55-81b2-9e2790a18266.jpg' May 31 17:55:07 primo volumio[3513]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 17:55:07 primo volumio[3513]: TypeError: Cannot read property 'slice' of null May 31 17:55:07 primo volumio[3513]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) May 31 17:55:07 primo volumio[3513]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) May 31 17:55:07 primo volumio[3513]: at Object.onceWrapper (events.js:520:26) May 31 17:55:07 primo volumio[3513]: at ClientRequest.emit (events.js:400:28) May 31 17:55:07 primo volumio[3513]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) May 31 17:55:07 primo volumio[3513]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) May 31 17:55:07 primo volumio[3513]: at TLSSocket.socketOnData (_http_client.js:515:22) May 31 17:55:07 primo volumio[3513]: at TLSSocket.emit (events.js:400:28) May 31 17:55:07 primo volumio[3513]: at addChunk (internal/streams/readable.js:293:12) May 31 17:55:07 primo volumio[3513]: at readableAddChunk (internal/streams/readable.js:267:9) May 31 17:55:07 primo volumio[3513]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) May 31 17:55:07 primo volumio[3513]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) May 31 17:55:07 primo volumio[3513]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 17:55:08 primo sudo[7378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-31 17:54 May 31 17:55:08 primo sudo[7378]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 12:16:07 PM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="88686576587e39571d6cf25f3920fbc0"