Aug 30 16:42:03 primo bluealsa[3353]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_68_3C_E5_2E_D8_A4, ...) Aug 30 16:42:17 primo bluealsa[3353]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5A_AD_4B_70_36_63, ...) Aug 30 16:42:27 primo ntpd[3170]: PROTO: 212.45.144.206 unlink local addr 192.168.1.128 -> Aug 30 16:42:31 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"}] Aug 30 16:42:31 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:31 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Push Volumio state: {"status":"play","uri":"soundcloud/track@trackId=2366682467@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D","title":"dancingwithkupid","artist":"Zeweezy@saxkhaserlyf on ig","album":"SoundCloud Track","albumart":"https://i1.sndcdn.com/artworks-jIjGE8Gttd4zDqJA-NB0dyQ-t500x500.jpg","trackType":"mp3","duration":133.485714,"samplerate":"128 kbps","service":"soundcloud","seek":133161.043,"isStreaming":false,"repeat":null,"repeatSingle":false,"random":true,"volume":90,"mute":false,"disableVolumeControl":false} Aug 30 16:42:31 primo volumio[4395]: info: CoreCommandRouter::servicePushState Aug 30 16:42:31 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:31 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 16:42:31 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:31 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:31 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:31 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:31 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:31.605+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 133161.043 into Go struct field State.seek of type int" Aug 30 16:42:31 primo volumio[4395]: info: Signalling Playback active due to playback status change Aug 30 16:42:31 primo volumio[4395]: info: FusionDsp - Volumio is playing Aug 30 16:42:31 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:31 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Player status "stopped" - unsetting ourselves as current service... Aug 30 16:42:32 primo volumio[4395]: verbose: UNSET VOLATILE: Service: soundcloud Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Volatile state unset, stopping playback (if any)... Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [mpv] (PID: 6484) Push Volumio state: {"status":"stop","albumart":"/albumart","uri":"","seek":0,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":null,"repeatSingle":false,"random":true,"volume":90,"mute":false,"disableVolumeControl":false} Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::servicePushState Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 26 Aug 30 16:42:32 primo volumio[4395]: verbose: STATE SERVICE {"status":"stop","albumart":"/albumart","uri":"","seek":0,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":null,"repeatSingle":false,"random":true,"volume":90,"mute":false,"disableVolumeControl":false} Aug 30 16:42:32 primo volumio[4395]: verbose: CURRENT POSITION 26 Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::syncState stateService stop Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::syncState currentStatus play Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::play index undefined Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.142+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 133.485714 into Go struct field State.duration of type int" Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.143+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 133.485714 into Go struct field State.duration of type int" Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 41 Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::startPlaybackTimer Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 41 Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] clearAddPlayTrack: soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 41 Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 41 Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.166+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" state=STATUS_STOPPED positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.167+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" state=STATUS_STOPPED positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.167+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.167+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud-testing] Available transcodings: [{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2368022033/471103d8-7476-4b3c-85b3-5800b383cb65/stream/hls","preset":"aac_160k","protocol":"hls","mimeType":"audio/mp4; codecs=\"mp4a.40.2\"","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2368022033/876693f5-878f-4c91-9f65-c25354662418/stream/hls","preset":"aac_96k","protocol":"hls","mimeType":"audio/mp4; codecs=\"mp4a.40.2\"","quality":"lq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2368022033/ae61e98f-a49d-4958-884a-50bbdd36cc87/stream/hls","preset":"abr_sq","protocol":"hls","mimeType":"audio/mpegurl","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2368022033/a1a79890-116b-435d-a36e-348347f538d0/stream/hls","preset":"mp3_1_0","protocol":"hls","mimeType":"audio/mpeg","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2368022033/a1a79890-116b-435d-a36e-348347f538d0/stream/progressive","preset":"mp3_1_0","protocol":"progressive","mimeType":"audio/mpeg","quality":"sq"}] Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud-testing] Chosen transcoding: {"format":"aac_160k+hls","codec":"aac","protocol":"hls","bitrate":"160 kbps","transcodingUrl":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2368022033/471103d8-7476-4b3c-85b3-5800b383cb65/stream/hls"} Aug 30 16:42:32 primo volumio[4395]: info: Signalling Playback active due to playback status change Aug 30 16:42:32 primo volumio[4395]: info: Signalling Playback active due to playback status change Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Volumio is playing Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Volumio is playing Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Volumio is not playing Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Clipped samples monitor stopped Aug 30 16:42:32 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:32 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:32 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:32 primo volumio[4395]: info: MCU Signalled Playback Inactive Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 41 Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: CorePlayQueue::getTrack 41 Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) Stopping playback by current service... Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioStop Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::stop Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) Setting ourselves as the current service... Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) Push Volumio state: {"status":"pause","albumart":"https://i1.sndcdn.com/artworks-dWzjVtPL2WyT5lwB-bKFj5A-t500x500.jpg","uri":"soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D","seek":0,"duration":0,"service":"soundcloud","artist":"kiddntcare","album":"SoundCloud Track","name":"FAST","title":"FAST","trackType":"aac","samplerate":"160 kbps","isStreaming":false,"repeat":null,"repeatSingle":false,"random":true,"volume":90,"mute":false,"disableVolumeControl":false} Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::servicePushState Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.394+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" state=STATUS_PAUSED positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.395+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" state=STATUS_PAUSED positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.395+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.395+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Volumio is not playing Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Clipped samples monitor stopped Aug 30 16:42:32 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) Push Volumio state: {"status":"play","uri":"soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D","title":"FAST","artist":"kiddntcare","album":"SoundCloud Track","albumart":"https://i1.sndcdn.com/artworks-dWzjVtPL2WyT5lwB-bKFj5A-t500x500.jpg","trackType":"aac","duration":-1,"samplerate":"160 kbps","service":"soundcloud","seek":0,"isStreaming":false,"repeat":null,"repeatSingle":false,"random":true,"volume":90,"mute":false,"disableVolumeControl":false} Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::servicePushState Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.461+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" state=STATUS_PLAYING positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.461+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" state=STATUS_PLAYING positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.462+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.462+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio[4395]: info: Signalling Playback active due to playback status change Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Volumio is playing Aug 30 16:42:32 primo volumio[4395]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Aug 30 16:42:32 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Clipping Monitor started Aug 30 16:42:32 primo volumio[4395]: info: MCU Signalled Playback Active Aug 30 16:42:32 primo kernel: asoc-aml-card auge_sound: tdm playback stop Aug 30 16:42:32 primo kernel: spdif_a is set to disable Aug 30 16:42:32 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Aug 30 16:42:32 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Aug 30 16:42:32 primo kernel: tdm playback mute: 1, lane_cnt = 8 Aug 30 16:42:32 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Clipping Monitor reconnecting in 2000ms Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Clipping Monitor reconnecting in 4000ms Aug 30 16:42:32 primo volumio[4395]: info: camilladsp respawn in 100 ms (attempt 1/10) Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) Push Volumio state: {"status":"play","uri":"soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D","title":"FAST","artist":"kiddntcare","album":"SoundCloud Track","albumart":"https://i1.sndcdn.com/artworks-dWzjVtPL2WyT5lwB-bKFj5A-t500x500.jpg","trackType":"aac","duration":129,"samplerate":"160 kbps","service":"soundcloud","seek":0,"isStreaming":false,"repeat":null,"repeatSingle":false,"random":true,"volume":90,"mute":false,"disableVolumeControl":false} Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::servicePushState Aug 30 16:42:32 primo volumio[4395]: info: CoreStateMachine::pushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioPushState Aug 30 16:42:32 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output update for this device Aug 30 16:42:32 primo volumio[4395]: info: MRS: Pushing multiroomSync output Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.817+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" state=STATUS_PLAYING positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.817+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" state=STATUS_PLAYING positionMs=0 volume=90 Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.818+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.227:49879 @ 0x1f44de0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:32.818+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.150:51233 @ 0x1cb29f0" id="soundcloud/track@trackId=2368022033@origin:o=%7B%22type%22%3A%22playlist%22%2C%22playlistId%22%3A1780168467%7D" title=FAST Aug 30 16:42:32 primo volumio[4395]: info: Signalling Playback active due to playback status change Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Volumio is playing Aug 30 16:42:32 primo volumio[4395]: info: Updating RAAT Signal Path Aug 30 16:42:32 primo volumio[4395]: error: FusionDsp - Monitor WebSocket error: [object Object] Aug 30 16:42:32 primo volumio[4395]: info: FusionDsp - Clipping Monitor reconnecting in 8000ms Aug 30 16:42:32 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] adaptive demux: Changing stream format Unknown -> MP4 Aug 30 16:42:33 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f1dfb0b8] mp4 demux: Fragment sequence discontinuity detected 1 != 0 Aug 30 16:42:33 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 1 error: Cancellation (0x8) Aug 30 16:42:33 primo kernel: aml_tdm_open Aug 30 16:42:33 primo kernel: Not init audio effects Aug 30 16:42:33 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Aug 30 16:42:33 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Aug 30 16:42:33 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Aug 30 16:42:33 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Aug 30 16:42:33 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc0501eea18, id(1), clksel(1) Aug 30 16:42:33 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Aug 30 16:42:33 primo kernel: dump_pcm_setting(ffffffc0501eea18) Aug 30 16:42:33 primo kernel: pcm_mode(1) Aug 30 16:42:33 primo kernel: sysclk(11289600) Aug 30 16:42:33 primo kernel: sysclk_bclk_ratio(4) Aug 30 16:42:33 primo kernel: bclk(2822400) Aug 30 16:42:33 primo kernel: bclk_lrclk_ratio(64) Aug 30 16:42:33 primo kernel: lrclk(44100) Aug 30 16:42:33 primo kernel: tx_mask(0x3) Aug 30 16:42:33 primo kernel: rx_mask(0x3) Aug 30 16:42:33 primo kernel: slots(2) Aug 30 16:42:33 primo kernel: slot_width(32) Aug 30 16:42:33 primo kernel: lane_mask_in(0x2) Aug 30 16:42:33 primo kernel: lane_mask_out(0x1) Aug 30 16:42:33 primo kernel: lane_oe_mask_in(0x0) Aug 30 16:42:33 primo kernel: lane_oe_mask_out(0x0) Aug 30 16:42:33 primo kernel: lane_lb_mask_in(0x0) Aug 30 16:42:33 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Aug 30 16:42:33 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Aug 30 16:42:33 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Aug 30 16:42:33 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Aug 30 16:42:33 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Aug 30 16:42:33 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Aug 30 16:42:33 primo kernel: aml_tdm_prepare(), reset fddr Aug 30 16:42:33 primo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Aug 30 16:42:33 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Aug 30 16:42:33 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Aug 30 16:42:33 primo kernel: tdm playback mute: 0, lane_cnt = 8 Aug 30 16:42:33 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 3 error: Cancellation (0x8) Aug 30 16:42:33 primo volumio[4395]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Aug 30 16:42:33 primo volumio[4395]: info: FusionDsp - ---- read samplerate from file: 44100 Aug 30 16:42:33 primo volumio[4395]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Aug 30 16:42:33 primo volumio[4395]: info: FusionDsp - ---- read samplerate from file: 44100 Aug 30 16:42:33 primo kernel: asoc-aml-card auge_sound: tdm playback enable Aug 30 16:42:33 primo kernel: spdif_a is set to enable Aug 30 16:42:33 primo volumio[4395]: info: FusionDsp - If filter freq >samplerate/2 then disable it Aug 30 16:42:33 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 5 error: Cancellation (0x8) Aug 30 16:42:34 primo ntpd[3170]: PROTO: 85.199.214.99 unlink local addr 192.168.1.128 -> Aug 30 16:42:34 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 7 error: Cancellation (0x8) Aug 30 16:42:34 primo volumio[4395]: info: FusionDsp - Clipping Monitor started Aug 30 16:42:42 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 9 error: Cancellation (0x8) Aug 30 16:42:51 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:51.693+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.150:51233 @ 0x1cb29f0" latency=21.547885ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Aug 30 16:42:51 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:51.891+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s Aug 30 16:42:51 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:51.957+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=http://pushupdates.volumio.org duration=65.358314ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.102+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=210.81981ms Aug 30 16:42:52 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 11 error: Cancellation (0x8) Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.225+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://www.googleapis.com duration=332.89842ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.311+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://securetoken.googleapis.com duration=418.890824ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.364+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=471.270527ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.394+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=500.567301ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.405+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=512.987454ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.412+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=http://cddb.volumio.org duration=518.789092ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.464+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=http://plugins.volumio.org duration=572.540381ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.515+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://functions.volumio.cloud duration=622.97762ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.522+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://functions.volumio.cloud duration=628.02059ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.544+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://database.volumio.cloud duration=651.588894ms Aug 30 16:42:52 primo volumio5-onboarding[3951]: time=2026-08-30T16:42:52.695+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.150:51233 @ 0x1cb29f0" latency=205.687657ms timeout=10s endpoint=https://google.com duration=802.93132ms Aug 30 16:42:53 primo sudo[7139]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 30 16:42:53 primo sudo[7139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 16:42:53 primo sudo[7139]: pam_unix(sudo:session): session closed for user root Aug 30 16:42:53 primo sudo[7141]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 30 16:42:53 primo sudo[7141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 16:42:53 primo sudo[7141]: pam_unix(sudo:session): session closed for user root Aug 30 16:42:53 primo volumio[4395]: verbose: New Socket.io Connection to 192.168.1.128 from 192.168.1.150 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Aug 30 16:42:53 primo sudo[7147]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 30 16:42:53 primo sudo[7147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 16:42:53 primo sudo[7149]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 30 16:42:53 primo sudo[7149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 30 16:42:53 primo sudo[7147]: pam_unix(sudo:session): session closed for user root Aug 30 16:42:53 primo sudo[7149]: pam_unix(sudo:session): session closed for user root Aug 30 16:42:53 primo volumio[4395]: verbose: New Socket.io Connection to 192.168.1.128 from 192.168.1.150 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Aug 30 16:42:53 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:42:53 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 30 16:42:53 primo volumio[4395]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Aug 30 16:42:53 primo volumio[4395]: info: Listing playlists Aug 30 16:42:53 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 30 16:42:53 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 30 16:42:53 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 30 16:42:53 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 16:43:02 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 13 error: Cancellation (0x8) Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 30 16:43:11 primo volumio[4395]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 30 16:43:11 primo volumio[4395]: info: Received Get System Version Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 30 16:43:11 primo volumio[4395]: info: Received Get System Info Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 16:43:11 primo volumio[4395]: info: Discovery: Getting this device information Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::volumioGetState Aug 30 16:43:11 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 16:43:12 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 15 error: Cancellation (0x8) Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:14 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:14 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:15 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Aug 30 16:43:15 primo volumio[4395]: error: MRS: impossible to set browserPlayback volume: device not found Aug 30 16:43:17 primo ntpd[3170]: PROTO: 172.232.209.103 unlink local addr 192.168.1.128 -> Aug 30 16:43:22 primo volumio[4395]: info: [soundcloud] [vlc] (PID: 5380) [f5f2a950] http demux error: local stream 17 error: Cancellation (0x8) Aug 30 16:43:22 primo volumio[4395]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Aug 30 16:43:22 primo volumio[4395]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Aug 30 16:43:22 primo volumio[4395]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 16:43:22 primo volumio[4395]: TypeError: Cannot read properties of undefined (reading 'then') Aug 30 16:43:22 primo volumio[4395]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Aug 30 16:43:22 primo volumio[4395]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Aug 30 16:43:22 primo volumio[4395]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1467:26) Aug 30 16:43:22 primo volumio[4395]: at Socket.emit (node:events:514:28) Aug 30 16:43:22 primo volumio[4395]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Aug 30 16:43:22 primo volumio[4395]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 30 16:43:22 primo volumio[4395]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 16:43:23 primo sudo[7218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-30 16:42' Aug 30 16:43:23 primo sudo[7218]: 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"