Aug 30 01:05:00 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:00 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:00 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:00 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:00 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:00 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:00 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:00 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:00 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:00 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:00 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:00 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:00 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:00.986+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=191191 volume=99 Aug 30 01:05:00 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:00.987+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:01 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:01 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:01 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:01 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:01 primo volumio[3419]: info: CALLMETHOD: music_service inputs saveAdvancedAudioSettings [object Object] Aug 30 01:05:01 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , saveAdvancedAudioSettings Aug 30 01:05:01 primo volumio[3419]: info: Setting DAC Filter Mode to 1 (Linear phase fast roll-off) Aug 30 01:05:01 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:01 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:01 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:01 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:01 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:01 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:01 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:02 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:02.046+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=192253 volume=99 Aug 30 01:05:02 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:02.047+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:02 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:02 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:02 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:02 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:02 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:02 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:02 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:02 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:02 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:02 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:02 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:02 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:03 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:03.168+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=193332 volume=99 Aug 30 01:05:03 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:03.169+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:03 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:03 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:03 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:03 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:03 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:03 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:03.652+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=81 index=0 tries=11 Aug 30 01:05:03 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:03 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:03 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:03.952+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=81 index=0 tries=11 Aug 30 01:05:03 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:03 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:04 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:04 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:04 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:04 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:04 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:04.323+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=194472 volume=99 Aug 30 01:05:04 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:04.323+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:04 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:04 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:04 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:04 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:05 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:05 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:05 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:05 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:05 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:05 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:05 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:05 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:05.452+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=195590 volume=99 Aug 30 01:05:05 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:05.453+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:05 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:05 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:05 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:05 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:05 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:06 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:06 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:06 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:06 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:06 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:06 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:06 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:06 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:06 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:06.498+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=196670 volume=99 Aug 30 01:05:06 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:06.499+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:06 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:06 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:06 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:06 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:07 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:07 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:07 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:07 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:07 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:07 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:07 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:07 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:07 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:07.713+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=197841 volume=99 Aug 30 01:05:07 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:07.716+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:07 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:07 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:08 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:08 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:08 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:08 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:08 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:08 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:08 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:08 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:08 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:08 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:08.845+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=198951 volume=99 Aug 30 01:05:08 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:08.846+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:08 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:08 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:09 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:09 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:09 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:09 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:09 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:09 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:09 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:09 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:09 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:09 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:09 primo kernel: DI: DI: tasklet schedule cost 12ms. Aug 30 01:05:09 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:09 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:09.975+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=200094 volume=99 Aug 30 01:05:09 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:09.975+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:10 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:10 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:10 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:10 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:10 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:10 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:10 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:10 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:10 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:10 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:10 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:11 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:11.033+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=201170 volume=99 Aug 30 01:05:11 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:11.034+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:11 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:11 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:11 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:11 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:11 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:11 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:11 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:11 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:11 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:11 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:11 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:11 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:11 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:11.997+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=1 index=0 tries=11 Aug 30 01:05:12 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:12 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:12.069+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=202231 volume=99 Aug 30 01:05:12 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:12.070+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:12 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:12 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:12 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:12 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:12 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:12.713+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Aug 30 01:05:12 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:12 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:12 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:12 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:12 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:12 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:12 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:13 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:13 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:13.149+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=203332 volume=99 Aug 30 01:05:13 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:13.150+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:13 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:13 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:13 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:13 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:13 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:13 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:13 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:13 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:13 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:13 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:14 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:14 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:14.328+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=204412 volume=99 Aug 30 01:05:14 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:14.329+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:14 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:14 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:14 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:14 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:14 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:14 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:14 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:14 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:14 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:15 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:15 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:15 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:15 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:15.375+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=205499 volume=99 Aug 30 01:05:15 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:15.376+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:15 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:15 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:15 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:15 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:15 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:16 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:16 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:16 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:16 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:16.509+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=206639 volume=99 Aug 30 01:05:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:16.512+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:16 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:16 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:16 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:16 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:16 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:17 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:17 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:17 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:17 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:17.692+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=207712 volume=99 Aug 30 01:05:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:17.693+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:17 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:17 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:18 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:18 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:18 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:18 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:18 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:18 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:18 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:18 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:18 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:18 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:18.711+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=208813 volume=99 Aug 30 01:05:18 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:18.712+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:18 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:18 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:18 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:18 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:18 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:19 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:19 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:19 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:19 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:19 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:19 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:19 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:19.873+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=209915 volume=99 Aug 30 01:05:19 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:19.874+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:19 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:19 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:20 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:20 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:20 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:20 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:20 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:20 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:20 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:20.759+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=210349 volume=99 Aug 30 01:05:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:20.760+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:20 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:20 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:20 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:20 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:21 primo volumio[3419]: ------------------------------------ BT MESSAGE: Received new metadata for 88:2F:92:D7:C9:89 Aug 30 01:05:21 primo volumio[3419]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-88:2F:92:D7:C9:89.json Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:21 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:21 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:21 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.339+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=0 volume=99 Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.340+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Tame Impala - Dracula (JENNIE Remix - Official Lyric Video) ft. JENNIE" Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.376+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=0 volume=99 Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.376+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=0 volume=99 Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.378+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.378+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:21.473+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=1 index=0 tries=11 Aug 30 01:05:21 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:21 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:21 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:21 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:21 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:21 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:21 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:22 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:22.461+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=2188 volume=99 Aug 30 01:05:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:22.462+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:22 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:22 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:22 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:22 primo volumio[3419]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Aug 30 01:05:22 primo volumio[3419]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Aug 30 01:05:22 primo volumio[3419]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Aug 30 01:05:22 primo volumio[3419]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Aug 30 01:05:22 primo volumio[3419]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Aug 30 01:05:22 primo volumio[3419]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Aug 30 01:05:22 primo volumio[3419]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Aug 30 01:05:22 primo volumio[3419]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 30 01:05:22 primo volumio[3419]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 30 01:05:22 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:22 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: Received new metadata for 88:2F:92:D7:C9:89 Aug 30 01:05:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-88:2F:92:D7:C9:89.json Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:22 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:22 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:23.002+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=0 volume=99 Aug 30 01:05:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:23.002+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:23 primo volumio[3419]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Aug 30 01:05:23 primo volumio[3419]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Aug 30 01:05:23 primo volumio[3419]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Aug 30 01:05:23 primo volumio[3419]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Aug 30 01:05:23 primo volumio[3419]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Aug 30 01:05:23 primo volumio[3419]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Aug 30 01:05:23 primo volumio[3419]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Aug 30 01:05:23 primo volumio[3419]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 30 01:05:23 primo volumio[3419]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:23 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:23 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:23 primo volumio[3419]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Aug 30 01:05:23 primo volumio[3419]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Aug 30 01:05:23 primo volumio[3419]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Aug 30 01:05:23 primo volumio[3419]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Aug 30 01:05:23 primo volumio[3419]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Aug 30 01:05:23 primo volumio[3419]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Aug 30 01:05:23 primo volumio[3419]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Aug 30 01:05:23 primo volumio[3419]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 30 01:05:23 primo volumio[3419]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:23 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:23.170+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=2909 volume=99 Aug 30 01:05:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:23.170+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:23 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:23 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:23 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:23 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:23.554+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=3382 volume=99 Aug 30 01:05:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:23.555+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:23 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:23 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:23 primo volumio[3419]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Olivia%20Dean/Olivia%20Dean/178c872b-f5bd-41e7-9033-a5401aeea670.jpg' Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:23 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:23 primo volumio[3419]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Aug 30 01:05:23 primo volumio[3419]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Aug 30 01:05:23 primo volumio[3419]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Aug 30 01:05:23 primo volumio[3419]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Aug 30 01:05:23 primo volumio[3419]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Aug 30 01:05:23 primo volumio[3419]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Aug 30 01:05:23 primo volumio[3419]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Aug 30 01:05:23 primo volumio[3419]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Aug 30 01:05:23 primo volumio[3419]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 30 01:05:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:24.171+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Aug 30 01:05:24 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:24 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:24 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:24 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:24 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:24 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:24 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:24.688+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=4480 volume=99 Aug 30 01:05:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:24.689+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:24 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:24 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:24 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:24 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:24 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:25 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:25 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:25 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:25 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:25 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:25 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:25 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:25.773+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=5600 volume=99 Aug 30 01:05:25 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:25.774+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:25 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:25 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:25 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:26 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:26 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:26 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:26 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:26 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:26 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:26 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:26 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:26 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:26.904+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=6743 volume=99 Aug 30 01:05:26 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:26.905+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:26 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:26 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:26 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:27 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:27 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:28 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:28 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:28 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:28 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:28 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:28 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:28 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:28.139+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=7926 volume=99 Aug 30 01:05:28 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:28.141+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:28 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:28 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:28 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:28 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:28 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:29 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:29 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:29 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:29 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:29 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:29 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:29 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:29 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:29.559+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=9208 volume=99 Aug 30 01:05:29 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:29.561+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:29 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:29 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:29 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:29 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:29 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:30 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:30 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:30 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:30 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:30 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:30 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:30 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:30 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:30.768+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=10550 volume=99 Aug 30 01:05:30 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:30.770+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:30 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:30 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:30 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:31 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:31 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:31 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:31 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:31 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:31 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:31 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:31 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:31 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:31 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:31.849+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=11682 volume=99 Aug 30 01:05:31 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:31.851+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:31 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:31 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:31 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:32 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:32 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:32 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:32.512+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=84 index=0 tries=11 Aug 30 01:05:33 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:33 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:33 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:33 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:33 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:33 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:33 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:33 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:33.050+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=12872 volume=99 Aug 30 01:05:33 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:33.054+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:33 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:33 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:33 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:33 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:33 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:34 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:34 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:34 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:34 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:34 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:34 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:34 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:34 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:34.269+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=14067 volume=99 Aug 30 01:05:34 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:34.270+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:34 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:34 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:34 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:34 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:34 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:35 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:35 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:35 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:35 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:35 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:35 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:35 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:35 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:35.830+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=15490 volume=99 Aug 30 01:05:35 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:35.831+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:35 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:35 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:35 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:36 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:36 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:36 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:36.598+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s Aug 30 01:05:36 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:36.735+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=http://pushupdates.volumio.org duration=135.616989ms Aug 30 01:05:36 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:36.858+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=259.307498ms Aug 30 01:05:36 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:36.998+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://www.googleapis.com duration=394.82882ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.003+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://securetoken.googleapis.com duration=403.199227ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.041+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=440.297388ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.155+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=555.52728ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.158+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=557.910426ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.197+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=http://cddb.volumio.org duration=596.083847ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.240+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://functions.volumio.cloud duration=638.504013ms Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.254+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://database.volumio.cloud duration=652.498512ms Aug 30 01:05:37 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:37 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.262+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://functions.volumio.cloud duration=660.943628ms Aug 30 01:05:37 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:37 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:37 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:37 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:37 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.291+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=16825 volume=99 Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.292+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:37 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:37 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:37 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:37 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:37.388+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=http://plugins.volumio.org duration=788.564963ms Aug 30 01:05:37 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:37 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:38 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:38.213+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=6 chunks=57 index=28 tries=11 Aug 30 01:05:38 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:38 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:38 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:38 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:38 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:38 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:38 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:38 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:38.492+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134 @ 0x14b23f0" state=STATUS_PLAYING positionMs=18287 volume=99 Aug 30 01:05:38 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:38.493+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:38 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:38 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:38 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:38 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:38 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:39 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:39 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:39 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:39 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:39.606+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=19421 volume=99 Aug 30 01:05:39 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:39.609+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:39 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:39 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:39 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:39 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:39.772+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=81 index=0 tries=11 Aug 30 01:05:39 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:39 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 01:05:39 primo volumio[3419]: info: Discovery: Getting this device information Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:39 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 01:05:40 primo volumio[3419]: verbose: New Socket.io Connection to 192.168.1.26:3000 from 192.168.1.14 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Aug 30 01:05:40 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 01:05:40 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 01:05:40 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:40 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:40 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:40 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:40 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:40 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:40 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:40 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:40.732+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=20543 volume=99 Aug 30 01:05:40 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:40.733+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:40 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:40 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:40 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:40 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:40 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:41 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:41 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:41 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:41 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:41 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:41 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:41 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:41 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:41.855+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=21661 volume=99 Aug 30 01:05:41 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:41.856+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:41 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:41 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:41 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:42 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:42.101+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" latency=716.420341ms timeout=10s endpoint=https://google.com duration=5.499827788s Aug 30 01:05:42 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:42 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:42 primo ntpd[3142]: PROTO: 212.227.145.233 unlink local addr 192.168.1.26 -> Aug 30 01:05:42 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:42 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:42 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:42 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:42 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:42 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:42 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:42 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:42.941+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=22765 volume=99 Aug 30 01:05:42 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:42.942+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:42 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:42 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:42 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:43 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:43 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:44 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:44 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:44 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:44 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:44 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:44 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:44 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:44 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:44 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:44.049+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=23862 volume=99 Aug 30 01:05:44 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:44.049+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:44 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:44 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:44 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:44 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:45 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:45 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:45 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:45 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:45 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:45 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:45 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:45 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:45.164+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=24984 volume=99 Aug 30 01:05:45 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:45.165+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:45 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:45 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:45 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:45 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:45 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:46 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:46 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:46 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:46 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:46 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:46 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:46 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:46 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:46.298+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=26102 volume=99 Aug 30 01:05:46 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:46.299+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:46 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:46 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:46 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:46 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:46 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:47 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:47.151+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=1 index=0 tries=11 Aug 30 01:05:47 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:47 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:47 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:47 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:47 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:47 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:47 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:47 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:47.405+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=27230 volume=99 Aug 30 01:05:47 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:47 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:47.412+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:47 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:47 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:47 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:47 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:48 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:48 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:48 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:48 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:48 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:48 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:48 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:48 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:48.506+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=28321 volume=99 Aug 30 01:05:48 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:48.507+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:48 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:48 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:48 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:48 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:48 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:49 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:49 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:49 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:49 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:49 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:49 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:49 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:49 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:49.607+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=29427 volume=99 Aug 30 01:05:49 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:49.608+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:49 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:49 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:49 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:49 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:49 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:50 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:50 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:50 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:50 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:50 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:50 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:50 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:50 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:50.721+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=30541 volume=99 Aug 30 01:05:50 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:50.722+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:50 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:50 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:50 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:50 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:50.932+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Aug 30 01:05:50 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:50 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:51 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:51 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:51 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:51 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:51 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:51 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:51 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:51 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:51 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:51.853+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=31662 volume=99 Aug 30 01:05:51 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:51.854+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:51 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:51 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:52 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:52 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:52 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:52 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:52 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:52 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:52 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:52 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:52 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:52 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:52.980+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=32789 volume=99 Aug 30 01:05:52 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:52.981+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:52 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:52 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:52 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:53 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:53.095+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=87 index=0 tries=11 Aug 30 01:05:53 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:53 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:54 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:54 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:54 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:54 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:54 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:54 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:54 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:54 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:54.079+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=33900 volume=99 Aug 30 01:05:54 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:54.080+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:54 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:54 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:54 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:54 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:54 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:55 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:55 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:55 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:55 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:55 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:55 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:55 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:55 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:55.178+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=34981 volume=99 Aug 30 01:05:55 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:55.179+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:55 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:55 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:55 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:55 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:55 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:56 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:56 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:56 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:56 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:56 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:56 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:56 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:56 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:56.268+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=36082 volume=99 Aug 30 01:05:56 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:56.269+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:56 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:56 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:56 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:56 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:56 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:57 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:57 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:57 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:57 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:57 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:57 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:57 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:57 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:57.360+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=37183 volume=99 Aug 30 01:05:57 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:57.361+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:57 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:57 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:57 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:57 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:57 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:58 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:58 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:58 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:58 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:58 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:58 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:58 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:58 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:58.538+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=38301 volume=99 Aug 30 01:05:58 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:58.539+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:58 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:58 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:58 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:58 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:58 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:05:59 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:05:59 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:05:59 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:05:59 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:05:59 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:05:59 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:05:59 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:05:59 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:59.647+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=39461 volume=99 Aug 30 01:05:59 primo volumio5-onboarding[4415]: time=2026-08-30T01:05:59.648+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:05:59 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:05:59 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:05:59 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:05:59 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:05:59 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:00 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:00 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:00 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:00 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:00 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:00 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:00 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:00 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:00.744+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=40563 volume=99 Aug 30 01:06:00 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:00.745+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:00 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:00 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:00 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:00 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:00 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:01 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:01.552+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Aug 30 01:06:01 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:01 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:01 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:01 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:01 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:01 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:01 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:01 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:01.842+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=41660 volume=99 Aug 30 01:06:01 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:01.843+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:01 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:01 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:01 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:02 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:02 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:02 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:02 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:02 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:02 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:02 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:02 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:02 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:02 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:02 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:02.970+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=42781 volume=99 Aug 30 01:06:02 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:02.971+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:02 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:02 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:03 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:03 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:03 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:03.352+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=1 index=0 tries=11 Aug 30 01:06:03 primo ntpd[3142]: PROTO: 172.233.111.193 unlink local addr 192.168.1.26 -> Aug 30 01:06:04 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:04 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:04 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:04 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:04 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:04 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:04 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:04 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:04.141+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=43923 volume=99 Aug 30 01:06:04 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:04.142+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:04 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:04 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:04 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:04 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:04 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:04 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:04.852+02:00 level=INFO msg="new address was allocated" component=ble/conn old=7 new=8 Aug 30 01:06:05 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:05 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:05 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:05 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:05 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:05 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:05 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:05 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:05.331+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" state=STATUS_PLAYING positionMs=45105 volume=99 Aug 30 01:06:05 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:05.331+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:05 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:05 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:05 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:05 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:05 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:06 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:06 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:06 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:06 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:06 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:06 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:06 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:06 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:06.444+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=46248 volume=99 Aug 30 01:06:06 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:06.445+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:06 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:06 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:06 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:06 primo ntpd[3142]: PROTO: 172.233.111.111 unlink local addr 192.168.1.26 -> Aug 30 01:06:06 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:06 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:07 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:07 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:07 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:07 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:07 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:07 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:07 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:07 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:07.546+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=47361 volume=99 Aug 30 01:06:07 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:07.547+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:07 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:07 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:07 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:07 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:07 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:08 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:08 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:08 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:08 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:08 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:08 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:08 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:08 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:08.678+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=48465 volume=99 Aug 30 01:06:08 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:08.679+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%06,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:08 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:08 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:08 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:08 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:08 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:09 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:09.064+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=6 chunks=1 index=0 tries=11 Aug 30 01:06:09 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:09 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:09 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:09 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:09 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:09 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:09 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:09 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:09.797+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=49601 volume=99 Aug 30 01:06:09 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:09 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:09.804+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:09 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:09 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:10 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:10 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:10 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:10 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:10 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:10 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:10 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:10 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:10 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:10 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:10.914+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=50702 volume=99 Aug 30 01:06:10 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:10.915+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:10 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:10 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:10 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:11 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:11 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:11 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:11 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:11 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:11 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:11 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:11 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:12 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:12 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:12.027+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=51822 volume=99 Aug 30 01:06:12 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:12.028+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:12 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:12 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:12 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:12 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:12 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:13 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:13 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:13 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:13 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:13 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:13 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:13 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:13 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:13 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:13.161+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=52947 volume=99 Aug 30 01:06:13 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:13.162+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:13 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:13 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:13 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:13 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:14 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:14.177+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=6 chunks=63 index=0 tries=11 Aug 30 01:06:14 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:14 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:14 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:14 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:14 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:14 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:14 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:14 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:14.250+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=54042 volume=99 Aug 30 01:06:14 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:14.251+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:14 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:14 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:14 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:14 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:14 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:15 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:15 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:15 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:15 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:15.350+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=55142 volume=99 Aug 30 01:06:15 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:15.350+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:15 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:15 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:15 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:15 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:15 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:15 primo volumio[3419]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Aug 30 01:06:15 primo volumio[3419]: info: Restoring Previous Volume level: 99 false true Aug 30 01:06:15 primo volumio[3419]: info: VolumeController::SetAlsaVolume100 Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:15 primo sudo[6230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:15 primo sudo[6230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:15 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:15 primo sudo[6230]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:15 primo sudo[6232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:15 primo sudo[6232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:15 primo volumio[3419]: info: Enable softmixer device for audio device number 5 Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::volumioStop Aug 30 01:06:15 primo volumio[3419]: info: CoreStateMachine::stop Aug 30 01:06:15 primo volumio[3419]: info: CoreStateMachine::serviceStop Aug 30 01:06:15 primo volumio[3419]: info: CoreCommandRouter::serviceStop Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [FUNC] stop Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Aug 30 01:06:15 primo volumio[3419]: ------------------------------------ BT MESSAGE: Killing bluealsa-aplay process Aug 30 01:06:15 primo volumio[3419]: info: Enable softmixer device for audio device undefined Aug 30 01:06:15 primo bluealsa[3264]: ../src/ba-transport-pcm.c:453: Closing PCM: 16 Aug 30 01:06:15 primo bluealsa[3264]: ../src/ba-transport.c:203: PCM clients check keep-alive: 0 ms Aug 30 01:06:16 primo systemd[1]: Stopping mpd.service - Music Player Daemon... Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 30 01:06:16 primo volumio[3419]: info: Updating Volume Controller Parameters: Device: 5 Name: Volumio Preciso Mixer: PCM Max Vol: 100 Vol Curve; linear Vol Steps: 1 Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 30 01:06:16 primo volumio[3419]: info: Disabling external Volume Control Aug 30 01:06:16 primo volumio[3419]: info: Output device has changed, restarting MPD Aug 30 01:06:16 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:16 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:16 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:16 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:16 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:16 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:16 primo volumio[3419]: info: Output device has changed, restarting Shairport Sync Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:16 primo sudo[6240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:16 primo sudo[6240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:16 primo sudo[6240]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo sudo[6248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:16 primo sudo[6248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo volumio[3419]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 01:06:16 primo volumio[3419]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:16 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo vtcs[5125]: [2026-08-30 01:06:16.238] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Aug 30 01:06:16 primo vtcs[5125]: [2026-08-30 01:06:16.240] [tisoc] [error] [SpkconServer.cpp:383] recv error. client fd=8 errorno=104 error=Connection reset by peer Aug 30 01:06:16 primo vtcs[5125]: [2026-08-30 01:06:16.240] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Aug 30 01:06:16 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:16 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:16 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:16 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:16 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:16 primo volumio[3419]: info: Volume configurations have been set Aug 30 01:06:16 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:16 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Aug 30 01:06:16 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:16 primo sudo[6260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:16 primo sudo[6260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo sudo[6262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:16 primo sudo[6262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 30 01:06:16 primo volumio[3419]: info: Updating Volume Controller Parameters: Device: 5 Name: Volumio Preciso Mixer: PCM Max Vol: 100 Vol Curve; linear Vol Steps: 1 Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:16 primo systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:16 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:16 primo systemd[1]: vtcs.service: Deactivated successfully. Aug 30 01:06:16 primo systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 30 01:06:16 primo volumio[3419]: info: Disabling external Volume Control Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 30 01:06:16 primo sudo[6260]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: Bluetooth audio output stopped Aug 30 01:06:16 primo sudo[6262]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.517+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=55142 volume=100 Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.519+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:16 primo sudo[6279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:16 primo sudo[6279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.583+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=5 chunks=90 index=0 tries=11 Aug 30 01:06:16 primo sudo[6281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:16 primo sudo[6281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo sudo[6279]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo sudo[6288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:16 primo sudo[6288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo sudo[6281]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo sudo[6288]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo sudo[6296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:16 primo sudo[6296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo sudo[6297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:16 primo sudo[6297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo sudo[6267]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 01:06:16 primo sudo[6267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:16 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:16 primo sudo[6267]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:16 primo sudo[6296]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:16 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:16 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:16 primo sudo[6305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:16 primo sudo[6305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:16 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:16 primo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Aug 30 01:06:16 primo qobuz-connect[5169]: 20260830 01:06:16.864 [5169.5169] INFO SampleApp: Stopping Local configuration server Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.919+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=56242 volume=100 Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.920+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:16 primo volumio[3419]: ------------------------------------ BT MESSAGE: bluealsa-aplay exited with code null, signal SIGKILL Aug 30 01:06:16 primo volumio[3419]: info: FusionDsp - Clipping Monitor reconnecting in 2000ms Aug 30 01:06:16 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:16 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:16 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.988+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=56242 volume= Aug 30 01:06:16 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:16.989+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:16 primo volumio[3419]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Aug 30 01:06:16 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:17 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:17 primo volumio[3419]: info: camilladsp respawn in 100 ms (attempt 1/10) Aug 30 01:06:17 primo volumio[3419]: info: VolumeController:: alsactl monitor closed, code: 0 Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:17 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:17 primo volumio[3419]: info: FusionDsp - volume level for loudness gain applied 17.25 Aug 30 01:06:17 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:17 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:17 primo volumio[3419]: info: VolumeController:: Volume=100 Mute =false Aug 30 01:06:17 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:17.179+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=56242 volume=100 Aug 30 01:06:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:17.180+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:17 primo volumio[3419]: info: Software Volume ALSA configuration written Aug 30 01:06:17 primo volumio[3419]: info: Preparing to generate the ALSA configuration file Aug 30 01:06:17 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:17 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:17 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:17 primo volumio[3419]: info: VolumeController::SetAlsaVolume0 Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 0 - forwarding to Bluetooth device Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 0 - forwarding to Bluetooth device Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:17 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:17 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:17 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:17.339+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=56242 volume=0 Aug 30 01:06:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:17.339+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 30 01:06:17 primo volumio[3419]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 30 01:06:17 primo volumio[3419]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 30 01:06:17 primo volumio[3419]: info: Reading ALSA contributions from plugins. Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:17 primo sudo[6332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:17 primo sudo[6332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 30 01:06:17 primo sudo[6332]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:17 primo sudo[6336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:17 primo sudo[6336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Aug 30 01:06:17 primo volumio[3419]: info: FusionDsp - volume level for loudness 0 gain applied 17.25 Aug 30 01:06:17 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:17 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:17 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:17 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:17 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:17 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:17 primo sudo[6336]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:17 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:17 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:17 primo sudo[6353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:17 primo sudo[6353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:17 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:17 primo sudo[6353]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:17.962+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=57344 volume=0 Aug 30 01:06:17 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:17 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:17 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:17.972+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:17 primo sudo[6355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:17 primo sudo[6355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo volumio[3419]: info: FusionDsp - volume level for loudness 0 gain applied 17.25 Aug 30 01:06:18 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:18 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:18 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:18 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:18 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:18 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:18 primo volumio[3419]: info: Starting Shairport Sync Aug 30 01:06:18 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:18 primo sudo[6355]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:18 primo volumio[3419]: info: Executing endpoint restartRAATSocket Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:18 primo sudo[6359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 01:06:18 primo sudo[6359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:18 primo volumio[3419]: info: Asound.conf file written Aug 30 01:06:18 primo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 01:06:18 primo systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 01:06:18 primo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:18 primo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:18 primo sudo[6371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 30 01:06:18 primo sudo[6371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo sudo[6359]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo sudo[6371]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:18 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:18 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:18 primo volumio[3419]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Aug 30 01:06:18 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:18 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:18 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:18 primo volumio[3419]: Found hardware: "USB-Audio" "USB Mixer" "USB2fc6:6013" "" "" Aug 30 01:06:18 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:18 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:18 primo volumio[3419]: info: Output device has changed, restarting MPD Aug 30 01:06:18 primo volumio[3419]: info: Output device has changed, restarting Shairport Sync Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:18 primo sudo[6391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:18 primo sudo[6391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo sudo[6391]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo sudo[6395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:18 primo sudo[6395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo qobuz-connect[5169]: 20260830 01:06:18.449 [5169.5169] INFO SampleApp: shat down connection on UNIX socket Aug 30 01:06:18 primo systemd[1]: qobuz-connect.service: Deactivated successfully. Aug 30 01:06:18 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:18 primo volumio[3419]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 01:06:18 primo volumio[3419]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:18 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:18 primo sudo[6297]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo sudo[6305]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:18 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:18 primo volumio[3419]: info: Preparing to generate the ALSA configuration file Aug 30 01:06:18 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:18 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:18 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:18 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:18 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:18 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:18 primo sudo[6405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:18 primo sudo[6405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:18 primo volumio[3419]: ALSA lib pcm.c:2666:(snd_pcm_open_noupdate) Unknown PCM volumioMultiRoomServer Aug 30 01:06:18 primo volumio[3419]: aplay: main:831: audio open error: No such file or directory Aug 30 01:06:18 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:18 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:18 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:18 primo volumio[3419]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Aug 30 01:06:18 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:18 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:18 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:18 primo volumio[3419]: Found hardware: "USB-Audio" "USB Mixer" "USB2fc6:6013" "" "" Aug 30 01:06:18 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:18 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:18 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:18 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes Aug 30 01:06:18 primo volumio[3419]: info: Output device has changed, restarting MPD Aug 30 01:06:18 primo sudo[6405]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo sudo[6414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:18 primo sudo[6414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo volumio[3419]: info: Output device has changed, restarting Shairport Sync Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:18 primo sudo[6417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:18 primo sudo[6417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo sudo[6417]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo sudo[6420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:18 primo sudo[6420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:18 primo sudo[6414]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:18 primo volumio[3419]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 01:06:18 primo volumio[3419]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 01:06:18 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:19 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:19 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:19 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:19 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:19 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:19 primo sudo[6430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:19 primo sudo[6430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:19 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 30 01:06:19 primo volumio[3419]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; linear Vol Steps: 1 Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:19 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:19 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 30 01:06:19 primo volumio[3419]: info: Disabling external Volume Control Aug 30 01:06:19 primo sudo[6430]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:19 primo sudo[6446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:19 primo sudo[6448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:19 primo sudo[6452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:19 primo sudo[6458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6446]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6448]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6466]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:19 primo sudo[6466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6458]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6466]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:19 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:19 primo sudo[6472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:19 primo sudo[6472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:19 primo sudo[6452]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo sudo[6435]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 01:06:19 primo sudo[6435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 01:06:19 primo sudo[6474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:19 primo sudo[6474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:19 primo sudo[6435]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6474]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:19 primo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Aug 30 01:06:19 primo systemd[1]: qobuz-connect.service: Deactivated successfully. Aug 30 01:06:19 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:19 primo sudo[6488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:19 primo sudo[6488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:19 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:19 primo sudo[6472]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo sudo[6473]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:19 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:19 primo volumio[3419]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 30 01:06:19 primo volumio[3419]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 30 01:06:19 primo volumio[3419]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 30 01:06:19 primo volumio[3419]: info: Reading ALSA contributions from plugins. Aug 30 01:06:19 primo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:19 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:19 primo systemd[1]: qobuz-connect.service: Deactivated successfully. Aug 30 01:06:19 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:19 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:19 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:19 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:19 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:19 primo sudo[6488]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:19 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:19 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:19 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.025+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=58465 volume=0 Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:20 primo volumio[3419]: info: FusionDsp - volume level for loudness 0 gain applied 17.25 Aug 30 01:06:20 primo volumio[3419]: info: FusionDsp - volume level for loudness 0 gain applied 17.25 Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.044+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=59601 volume=0 Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.045+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:20 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:20 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:20 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:20 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:20 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:20 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:20 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.152+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=59601 volume= Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.153+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:20 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:20 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:20 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:20 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:20 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:20 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:20 primo volumio[3419]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Aug 30 01:06:20 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:20 primo volumio[3419]: info: Shairport-Sync Started Aug 30 01:06:20 primo volumio[3419]: info: FusionDsp - volume level for loudness gain applied 17.25 Aug 30 01:06:20 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:20 primo volumio[3419]: error: FusionDsp - Monitor WebSocket error: [object Object] Aug 30 01:06:20 primo volumio[3419]: info: FusionDsp - Clipping Monitor reconnecting in 4000ms Aug 30 01:06:20 primo volumio[3419]: info: Executing endpoint restartRAATSocket Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:20 primo sudo[6549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:20 primo sudo[6549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:20 primo sudo[6549]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:20 primo sudo[6554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:20 primo sudo[6554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:20 primo sudo[6555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:20 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:20.694+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=6 chunks=1 index=0 tries=11 Aug 30 01:06:20 primo sudo[6555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:20 primo sudo[6554]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:20 primo volumio[3419]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:20 primo volumio[3419]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:20 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:20 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:20 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:20 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:20 primo sudo[6555]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:20 primo sudo[6561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:20 primo sudo[6562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:20 primo sudo[6562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:20 primo sudo[6561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:20 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:20 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:20 primo volumio[3419]: info: VolumeController::SetAlsaVolume99 Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 99 - forwarding to Bluetooth device Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 99 - forwarding to Bluetooth device Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:20 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:20 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:20 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:20 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:20 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:20 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:20 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:20 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:20 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:20 primo sudo[6571]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 30 01:06:20 primo sudo[6571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:20 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:21.010+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=59601 volume=99 Aug 30 01:06:21 primo sudo[6562]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:21.012+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:21 primo volumio[3419]: info: RAAT: Requesting Headphone Status Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:21 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:21 primo systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Aug 30 01:06:21 primo sudo[6571]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:21 primo sudo[6581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:21 primo sudo[6581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:21 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:21 primo sudo[6561]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:21 primo sudo[6586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:21.244+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=60682 volume=99 Aug 30 01:06:21 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:21.251+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:21 primo sudo[6586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:21 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:21 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:21 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:21 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:21 primo volumio[3419]: info: Executing endpoint qc_getconfig Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Aug 30 01:06:21 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:21 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:21 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:21 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:21 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:21 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:21 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:21 primo volumio[3419]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:21 primo volumio[3419]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:21 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:21 primo volumio[3419]: info: RAAT: Requesting Headphone Status Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 30 01:06:21 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:21 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:21 primo volumio[3419]: info: Executing endpoint qc_getconfig Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Aug 30 01:06:21 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:21 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:21 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:21 primo sudo[6592]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 30 01:06:21 primo sudo[6592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:21 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:21 primo sudo[6586]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.697 [6498.6498] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Aug 30 01:06:21 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:21 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.704 [6498.6498] INFO VolumeManager: [0xacd19138]: Setting new playback volume: 75 Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.704 [6498.6498] INFO VolumeManager: [0xacd19138]: Setting new mute state: 0 Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.704 [6498.6498] INFO AudioStreamManager: [0xacd18e90]: Setting new audio download buffer size: 1048576 Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.704 [6498.6498] INFO QobuzConnect: [0xacd19a00]: Client initialized! Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.704 [6498.6498] INFO SampleApp: Starting Avahi advertising, name: Primo, service name: _qobuz-connect._tcp Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.752 [6498.6498] INFO LocalConfigManager: [0xacd18bb8]: Starting Local Configuration server Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.753 [6498.6498] INFO SampleApp: Starting Local configuration server Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.754 [6498.6498] INFO SampleApp: Connected to UNIX socket client 0xacd038f8 Aug 30 01:06:21 primo volumio[3419]: info: Starting Shairport Sync Aug 30 01:06:21 primo sudo[6592]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:21 primo volumio[3419]: info: Starting Shairport Sync Aug 30 01:06:21 primo sudo[6606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 01:06:21 primo qobuz-connect[6498]: 20260830 01:06:21.848 [6498.6498] INFO SampleApp: Playback volume changed: 75 Aug 30 01:06:21 primo sudo[6606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:21 primo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 01:06:21 primo sudo[6608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 01:06:21 primo sudo[6608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:21 primo volumio[3419]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Aug 30 01:06:21 primo volumio[3419]: info: QobuzConnect: QOBUZ Connect daemon connected Aug 30 01:06:21 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:21 primo systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 01:06:21 primo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:21 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:22 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:22 primo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:22 primo sudo[6606]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:22 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:22.110+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=61782 volume=99 Aug 30 01:06:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:22.110+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:22 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:22 primo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 01:06:22 primo volumio[3419]: info: FusionDsp - volume level for loudness 99 gain applied 0 Aug 30 01:06:22 primo systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 01:06:22 primo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:22 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:22 primo volumio[3419]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 30 01:06:22 primo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:22 primo sudo[6608]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:22 primo volumio[3419]: info: Shairport-Sync Started Aug 30 01:06:22 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:22 primo volumio[3419]: info: Shairport-Sync Started Aug 30 01:06:22 primo volumio[3419]: (node:3419) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Aug 30 01:06:22 primo volumio[3419]: (node:3419) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Aug 30 01:06:22 primo volumio[3419]: (node:3419) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Aug 30 01:06:22 primo volumio[3419]: (node:3419) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Aug 30 01:06:22 primo volumio[3419]: (node:3419) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Aug 30 01:06:22 primo volumio[3419]: info: Asound.conf file written Aug 30 01:06:22 primo sudo[6593]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 01:06:22 primo sudo[6593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 01:06:22 primo sudo[6627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 30 01:06:22 primo sudo[6627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:22 primo sudo[6593]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:22 primo sudo[6627]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:22 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:22 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:22 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:22 primo volumio[3419]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Aug 30 01:06:22 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:22 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:22 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:22 primo volumio[3419]: Found hardware: "USB-Audio" "USB Mixer" "USB2fc6:6013" "" "" Aug 30 01:06:22 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:22 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:22 primo volumio[3419]: info: Output device has changed, restarting MPD Aug 30 01:06:22 primo sudo[6635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:22 primo sudo[6635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:22 primo volumio[3419]: info: Output device has changed, restarting Shairport Sync Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:22 primo sudo[6635]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:22.499+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Aug 30 01:06:22 primo sudo[6638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:22 primo sudo[6638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:22 primo volumio[3419]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 01:06:22 primo volumio[3419]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:22 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:22 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:22 primo volumio[3419]: info: Preparing to generate the ALSA configuration file Aug 30 01:06:22 primo sudo[6647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:22 primo sudo[6647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:22 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:22 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:22 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:22 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:22 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:22 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:22 primo sudo[6652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:22 primo sudo[6652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:22 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:22 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:22 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:22 primo volumio[3419]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 30 01:06:22 primo volumio[3419]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 30 01:06:22 primo volumio[3419]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 30 01:06:22 primo volumio[3419]: info: Reading ALSA contributions from plugins. Aug 30 01:06:22 primo volumio[3419]: info: VolumeController::SetAlsaVolume98 Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 98 - forwarding to Bluetooth device Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 98 - forwarding to Bluetooth device Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:22 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:22 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:22 primo sudo[6658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:22 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:22 primo sudo[6658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:22 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:22 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:22 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:22 primo sudo[6658]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:22.978+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=61782 volume=98 Aug 30 01:06:22 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:22.979+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:22 primo systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Aug 30 01:06:23 primo sudo[6662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:23 primo sudo[6662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:23 primo volumio[3419]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Aug 30 01:06:23 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:23 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:23 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:23 primo qobuz-connect[6498]: 20260830 01:06:23.072 [6498.6498] INFO SampleApp: Stopping Local configuration server Aug 30 01:06:23 primo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Aug 30 01:06:23 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:23 primo volumio[3419]: info: FusionDsp - volume level for loudness 98 gain applied 0 Aug 30 01:06:23 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:23 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:23 primo systemd[1]: vtcs.service: Deactivated successfully. Aug 30 01:06:23 primo systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Aug 30 01:06:23 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:23 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:23 primo sudo[6647]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:23 primo sudo[6661]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 01:06:23 primo sudo[6661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 01:06:23 primo volumio[3419]: info: VolumeController::SetAlsaVolume41 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 41 - forwarding to Bluetooth device Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 41 - forwarding to Bluetooth device Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:23 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:23 primo sudo[6661]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:23 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:23 primo sudo[6652]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:23.651+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=61782 volume=41 Aug 30 01:06:23 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:23.652+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:23 primo volumio[3419]: info: Updating RAAT Signal Path Aug 30 01:06:23 primo volumio[3419]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:23 primo volumio[3419]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:23 primo volumio[3419]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:23 primo volumio[3419]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:23 primo sudo[6702]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 30 01:06:23 primo sudo[6702]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:23 primo volumio[3419]: info: RAAT: Requesting Headphone Status Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 30 01:06:23 primo volumio[3419]: info: RAAT: Requesting Headphone Status Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo sudo[6705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 30 01:06:23 primo sudo[6705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:23 primo qobuz-connect[6498]: 20260830 01:06:23.776 [6498.6498] INFO SampleApp: shat down connection on UNIX socket Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:23 primo systemd[1]: qobuz-connect.service: Deactivated successfully. Aug 30 01:06:23 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:23 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:23 primo volumio[3419]: info: VolumeController::SetAlsaVolume100 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 100 - forwarding to Bluetooth device Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = 88:2F:92:D7:C9:89 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 88:2F:92:D7:C9:89 Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 88:2F:92:D7:C9:89: {"Volume":true} Aug 30 01:06:23 primo volumio[3419]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setVolume Aug 30 01:06:23 primo volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [setVolume] in plugin alsa_controller Aug 30 01:06:23 primo sudo[6662]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:23 primo systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Aug 30 01:06:23 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:23 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:23 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:23 primo sudo[6702]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:23 primo sudo[6705]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:24 primo volumio[3419]: info: FusionDsp - volume level for loudness 41 gain applied 6.727500000000001 Aug 30 01:06:24 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:24.058+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=61782 volume=100 Aug 30 01:06:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:24.060+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:24 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:24 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:24 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:24 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:24 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:24.164+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=63341 volume=100 Aug 30 01:06:24 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:24 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:24.175+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:24 primo volumio[3419]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:24 primo volumio[3419]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:24 primo volumio[3419]: info: RAAT: Requesting Headphone Status Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:24 primo sudo[6720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 30 01:06:24 primo sudo[6720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:24 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:24 primo sudo[6720]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:24 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:24 primo volumio[3419]: info: Executing endpoint restartRAATSocket Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Aug 30 01:06:24 primo volumio[3419]: info: TidalConnect service started! Aug 30 01:06:24 primo volumio[3419]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Aug 30 01:06:24 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:24 primo sudo[6725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:24 primo sudo[6725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:24 primo sudo[6725]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:24 primo sudo[6729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:24 primo sudo[6729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:24 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:24 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:24 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:24 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:24 primo sudo[6729]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:24 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:24 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:24 primo volumio[3419]: info: Starting Shairport Sync Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:24 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:24 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:24 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:24 primo sudo[6737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 01:06:24 primo sudo[6737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:24 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:24 primo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 01:06:25 primo systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 01:06:25 primo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:25 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:25.040+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=64487 volume=100 Aug 30 01:06:25 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:25.041+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:25 primo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:25 primo sudo[6737]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:25 primo volumio[3419]: error: FusionDsp - Monitor WebSocket error: [object Object] Aug 30 01:06:25 primo volumio[3419]: info: FusionDsp - Clipping Monitor reconnecting in 8000ms Aug 30 01:06:25 primo volumio[3419]: info: Executing endpoint qc_getconfig Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.177 [6713.6713] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Aug 30 01:06:25 primo volumio[3419]: info: TidalConnect service started! Aug 30 01:06:25 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.192 [6713.6713] INFO VolumeManager: [0xab6be138]: Setting new playback volume: 75 Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.192 [6713.6713] INFO VolumeManager: [0xab6be138]: Setting new mute state: 0 Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.192 [6713.6713] INFO AudioStreamManager: [0xab6bde90]: Setting new audio download buffer size: 1048576 Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.192 [6713.6713] INFO QobuzConnect: [0xab6bea00]: Client initialized! Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.192 [6713.6713] INFO SampleApp: Starting Avahi advertising, name: Primo, service name: _qobuz-connect._tcp Aug 30 01:06:25 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:25 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.237 [6713.6713] INFO LocalConfigManager: [0xab6bdbb8]: Starting Local Configuration server Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.237 [6713.6713] INFO SampleApp: Starting Local configuration server Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.238 [6713.6713] INFO SampleApp: Connected to UNIX socket client 0xab6a88f8 Aug 30 01:06:25 primo volumio[3419]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Aug 30 01:06:25 primo volumio[3419]: info: QobuzConnect: QOBUZ Connect daemon connected Aug 30 01:06:25 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:25 primo volumio[3419]: info: Shairport-Sync Started Aug 30 01:06:25 primo volumio[3419]: info: Executing endpoint tc_getconfig Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Aug 30 01:06:25 primo vtcs[6716]: STARTING TidalConnect services, version: 1.6.1 Aug 30 01:06:25 primo vtcs[6716]: STARTED TidalConnect services. Aug 30 01:06:25 primo qobuz-connect[6713]: 20260830 01:06:25.327 [6713.6713] INFO SampleApp: Playback volume changed: 75 Aug 30 01:06:25 primo volumio[3419]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 30 01:06:25 primo volumio[3419]: info: Asound.conf file written Aug 30 01:06:25 primo sudo[6765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 30 01:06:25 primo sudo[6765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:25 primo sudo[6765]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:25 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:25 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:25 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:25 primo volumio[3419]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Aug 30 01:06:25 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:25 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:25 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:25 primo volumio[3419]: Found hardware: "USB-Audio" "USB Mixer" "USB2fc6:6013" "" "" Aug 30 01:06:25 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:25 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:25 primo volumio[3419]: info: Output device has changed, restarting MPD Aug 30 01:06:25 primo volumio[3419]: info: Output device has changed, restarting Shairport Sync Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:25 primo sudo[6770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:25 primo sudo[6770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:25 primo sudo[6772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:25 primo sudo[6772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:25 primo sudo[6770]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:25 primo volumio[3419]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 01:06:25 primo volumio[3419]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:25 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:25 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Aug 30 01:06:25 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:25 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:25 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:25 primo volumio[3419]: info: Preparing to generate the ALSA configuration file Aug 30 01:06:25 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:25 primo sudo[6781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:25 primo sudo[6781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:25 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:25 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:26 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:26 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:26 primo systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Aug 30 01:06:26 primo sudo[6786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:26 primo systemd[1]: vtcs.service: Deactivated successfully. Aug 30 01:06:26 primo systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Aug 30 01:06:26 primo sudo[6786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:26 primo sudo[6781]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:26 primo sudo[6793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:26 primo sudo[6793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:26 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:26 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:26 primo volumio[3419]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 30 01:06:26 primo volumio[3419]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 30 01:06:26 primo volumio[3419]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 30 01:06:26 primo volumio[3419]: info: Reading ALSA contributions from plugins. Aug 30 01:06:26 primo volumio[3419]: info: Executing endpoint tc_connect Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Aug 30 01:06:26 primo volumio[3419]: info: Connecting to TidalConnect Aug 30 01:06:26 primo sudo[6793]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:26 primo volumio[3419]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Aug 30 01:06:26 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:26 primo sudo[6786]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:26 primo sudo[6799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:26 primo sudo[6799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:26 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:26 primo qobuz-connect[6713]: 20260830 01:06:26.430 [6713.6713] INFO SampleApp: Stopping Local configuration server Aug 30 01:06:26 primo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:26 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:26 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:26 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:26 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:26.496+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=66162 volume=100 Aug 30 01:06:26 primo volumio[3419]: info: FusionDsp - volume level for loudness 100 gain applied 0 Aug 30 01:06:26 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:26.500+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:26 primo volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 01:06:26 primo volumio[3419]: info: Executing endpoint restartRAATSocket Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:26 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 30 01:06:26 primo sudo[6785]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 01:06:26 primo sudo[6785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 01:06:26 primo sudo[6785]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:26 primo sudo[6818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Aug 30 01:06:26 primo sudo[6818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:26 primo sudo[6818]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:26 primo sudo[6821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 30 01:06:26 primo sudo[6821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:26 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:26 primo volumio[3419]: info: TidalConnect service stoped! Aug 30 01:06:26 primo volumio[3419]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 01:06:26 primo volumio[3419]: info: FusionDsp - Loudness is ON true Aug 30 01:06:26 primo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... Aug 30 01:06:26 primo systemd[1]: raat-daemon.service: Deactivated successfully. Aug 30 01:06:26 primo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. Aug 30 01:06:26 primo systemd[1]: Started raat-daemon.service - RAAT DAEMON. Aug 30 01:06:26 primo sudo[6821]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:26 primo volumio[3419]: info: Starting Shairport Sync Aug 30 01:06:26 primo volumio[3419]: error: FusionDsp - Reload WebSocket error: [object Object] Aug 30 01:06:26 primo volumio[3419]: info: Raat Daemon started successfully Aug 30 01:06:26 primo sudo[6833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 30 01:06:26 primo sudo[6833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo volumio[3419]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 30 01:06:27 primo volumio[3419]: info: TidalConnect service started! Aug 30 01:06:27 primo volumio[3419]: info: TidalConnect service started! Aug 30 01:06:27 primo volumio[3419]: info: Asound.conf file written Aug 30 01:06:27 primo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 30 01:06:27 primo systemd[1]: shairport-sync.service: Deactivated successfully. Aug 30 01:06:27 primo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:27 primo sudo[6840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 30 01:06:27 primo sudo[6840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 30 01:06:27 primo sudo[6840]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo sudo[6833]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:27 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:27 primo volumio[3419]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Aug 30 01:06:27 primo volumio[3419]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" Aug 30 01:06:27 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:27 primo volumio[3419]: No state is present for card AMLAUGESOUNDMP1 Aug 30 01:06:27 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:27 primo volumio[3419]: Found hardware: "USB-Audio" "USB Mixer" "USB2fc6:6013" "" "" Aug 30 01:06:27 primo volumio[3419]: Hardware is initialized using a generic method Aug 30 01:06:27 primo volumio[3419]: No state is present for card Preciso Aug 30 01:06:27 primo volumio[3419]: info: Output device has changed, restarting MPD Aug 30 01:06:27 primo qobuz-connect[6713]: 20260830 01:06:27.259 [6713.6713] INFO SampleApp: shat down connection on UNIX socket Aug 30 01:06:27 primo systemd[1]: qobuz-connect.service: Deactivated successfully. Aug 30 01:06:27 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:27 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:27.316+02:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=6 chunks=65 index=0 tries=11 Aug 30 01:06:27 primo volumio[3419]: info: Output device has changed, restarting Shairport Sync Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:27 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:27 primo sudo[6860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 30 01:06:27 primo sudo[6860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo sudo[6799]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo sudo[6860]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo sudo[6864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 30 01:06:27 primo sudo[6864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo volumio[3419]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 30 01:06:27 primo volumio[3419]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:27 primo volumio[3419]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: Preparing to generate the ALSA configuration file Aug 30 01:06:27 primo systemd[1]: mpd.service: Deactivated successfully. Aug 30 01:06:27 primo systemd[1]: Stopped mpd.service - Music Player Daemon. Aug 30 01:06:27 primo systemd[1]: mpd.socket: Deactivated successfully. Aug 30 01:06:27 primo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Aug 30 01:06:27 primo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Aug 30 01:06:27 primo sudo[6872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:27 primo sudo[6872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Aug 30 01:06:27 primo sudo[6876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 30 01:06:27 primo sudo[6876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo volumio[3419]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:27 primo volumio[3419]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 30 01:06:27 primo sudo[6882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Aug 30 01:06:27 primo sudo[6882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo systemd[1]: Starting mpd.service - Music Player Daemon... Aug 30 01:06:27 primo volumio[3419]: info: RAAT: Requesting Headphone Status Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 30 01:06:27 primo volumio[3419]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 30 01:06:27 primo volumio[3419]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 30 01:06:27 primo volumio[3419]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Aug 30 01:06:27 primo volumio[3419]: info: Reading ALSA contributions from plugins. Aug 30 01:06:27 primo volumio[3419]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Aug 30 01:06:27 primo volumio[3419]: info: MPD Permissions set Aug 30 01:06:27 primo volumio[3419]: info: TidalConnect service started! Aug 30 01:06:27 primo volumio[3419]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Aug 30 01:06:27 primo volumio[3419]: info: QobuzConnect: setDeactiveState invoked Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:27 primo volumio[3419]: info: Shairport-Sync Started Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo sudo[6886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 30 01:06:27 primo sudo[6886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 30 01:06:27 primo sudo[6882]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo sudo[6872]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo sudo[6876]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:27 primo sudo[6893]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Aug 30 01:06:27 primo sudo[6893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 01:06:27 primo volumio[3419]: info: Executing endpoint qc_getconfig Aug 30 01:06:27 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Aug 30 01:06:27 primo systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Aug 30 01:06:27 primo sudo[6886]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.054 [6862.6862] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.062 [6862.6862] INFO VolumeManager: [0xacf11138]: Setting new playback volume: 75 Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.063 [6862.6862] INFO VolumeManager: [0xacf11138]: Setting new mute state: 0 Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.064 [6862.6862] INFO AudioStreamManager: [0xacf10e90]: Setting new audio download buffer size: 1048576 Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.064 [6862.6862] INFO QobuzConnect: [0xacf11a00]: Client initialized! Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.065 [6862.6862] INFO SampleApp: Starting Avahi advertising, name: Primo, service name: _qobuz-connect._tcp Aug 30 01:06:28 primo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.130 [6862.6862] INFO LocalConfigManager: [0xacf10bb8]: Starting Local Configuration server Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.130 [6862.6862] INFO SampleApp: Starting Local configuration server Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.138 [6862.6862] INFO SampleApp: Stopping Local configuration server Aug 30 01:06:28 primo qobuz-connect[6862]: 20260830 01:06:28.159 [6862.6862] INFO SampleApp: shat down connection on UNIX socket Aug 30 01:06:28 primo systemd[1]: qobuz-connect.service: Main process exited, code=killed, status=11/SEGV Aug 30 01:06:28 primo systemd[1]: qobuz-connect.service: Failed with result 'signal'. Aug 30 01:06:28 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:28 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 30 01:06:28 primo sudo[6893]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 30 01:06:28 primo volumio[3419]: info: Not Reporting Auto name since its the default one Aug 30 01:06:28 primo volumio[3419]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Aug 30 01:06:28 primo volumio[3419]: info: QobuzConnect: QOBUZ Connect daemon connected Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 01:06:28 primo volumio[3419]: info: CoreStateMachine::pushState Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 01:06:28 primo volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 01:06:28 primo volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 01:06:28 primo volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 01:06:28 primo sudo[6884]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 30 01:06:28 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:28.530+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" state=STATUS_PLAYING positionMs=68007 volume=100 Aug 30 01:06:28 primo volumio5-onboarding[4415]: time=2026-08-30T01:06:28.533+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.14:51134,00:00:00:00:00:00%07 @ 0x14b23f0" id= title="Olivia Dean - So Easy (To Fall In Love)" Aug 30 01:06:28 primo sudo[6884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Aug 30 01:06:28 primo sudo[6884]: pam_unix(sudo:session): session closed for user root Aug 30 01:06:28 primo volumio[3419]: error: Error starting TidalConnect Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Aug 30 01:06:28 primo volumio[3419]: Job for vtcs.service canceled. Aug 30 01:06:28 primo volumio[3419]: {"cmd":"/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3","code":1,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3\nJob for vtcs.service canceled.\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)","stderr":"Job for vtcs.service canceled.\n","stdout":""} Aug 30 01:06:28 primo volumio[3419]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 01:06:28 primo volumio[3419]: Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Aug 30 01:06:28 primo volumio[3419]: Job for vtcs.service canceled. Aug 30 01:06:28 primo volumio[3419]: at ChildProcess.exithandler (node:child_process:421:12) Aug 30 01:06:28 primo volumio[3419]: at ChildProcess.emit (node:events:514:28) Aug 30 01:06:28 primo volumio[3419]: at maybeClose (node:internal/child_process:1105:16) Aug 30 01:06:28 primo volumio[3419]: at Socket. (node:internal/child_process:457:11) Aug 30 01:06:28 primo volumio[3419]: at Socket.emit (node:events:514:28) Aug 30 01:06:28 primo volumio[3419]: at Pipe. (node:net:337:12) { Aug 30 01:06:28 primo volumio[3419]: code: 1, Aug 30 01:06:28 primo volumio[3419]: killed: false, Aug 30 01:06:28 primo volumio[3419]: signal: null, Aug 30 01:06:28 primo volumio[3419]: cmd: '/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3', Aug 30 01:06:28 primo volumio[3419]: stdout: '', Aug 30 01:06:28 primo volumio[3419]: stderr: 'Job for vtcs.service canceled.\n' Aug 30 01:06:28 primo volumio[3419]: } Aug 30 01:06:28 primo volumio[3419]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 01:06:29 primo sudo[6923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 01:05' Aug 30 01:06:29 primo sudo[6923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="9ccd1247f8cab3c5d64c23a96d243f6bfa34d032" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="9938d7179e3b7c4e41f3e2d60c255985cff08fee" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun May 17 17:32:08 UTC 2026" VOLUMIO_VERSION="4.158" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="43d420a3aa41c50690ebfe378df38e2b"