Oct 13 10:31:00 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:01 primo-plus go-librespot[1878]: time="2026-10-13T10:31:01+01:00" level=debug msg="handling pause player command from 81d07e184e9d8d8a9299f9d05a21bc696bb38d0d" Oct 13 10:31:01 primo-plus go-librespot[1878]: time="2026-10-13T10:31:01+01:00" level=debug msg="pause track at 127150ms" Oct 13 10:31:02 primo-plus go-librespot[1878]: time="2026-10-13T10:31:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 10:31:02 primo-plus go-librespot[1878]: time="2026-10-13T10:31:02+01:00" level=debug msg="sending successful reply for dealer request" Oct 13 10:31:02 primo-plus go-librespot[1878]: time="2026-10-13T10:31:02+01:00" level=trace msg="emitting websocket event: paused" Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:5OQQPKEhkzpHjQ6qz9h9X8","uri":"spotify:track:7GGZjRWhtDZwusNFQf0ClL","play_origin":"playlist/ondemand"}} Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: {"status":"pause","service":"spop","title":"Ancestors","artist":"Steak","album":"Acute Mania","albumart":"https://i.scdn.co/image/ab67616d00001e02f3407be1550fdb9f624f348b","uri":"spotify:track:7GGZjRWhtDZwusNFQf0ClL","trackType":"spotify","seek":126415,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 10:31:02 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:02 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:02 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:02 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:02 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:02 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:02 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:02 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:02.074+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PAUSED positionMs=126415 volume=100 Oct 13 10:31:02 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:02.075+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=spotify:track:7GGZjRWhtDZwusNFQf0ClL title=Ancestors Oct 13 10:31:02 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:02 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:02 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:02 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:02 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:31:02 primo-plus go-librespot[1878]: time="2026-10-13T10:31:02+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 10:31:02 primo-plus volumio[1216]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 13 10:31:06 primo-plus volumio[1216]: verbose: New Socket.io Connection to 192.168.4.90 from 192.168.4.108 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: websocket Total Clients: 10 Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.625+01:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.721+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=http://pushupdates.volumio.org duration=89.594681ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.792+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=165.182306ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.834+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://www.googleapis.com duration=206.465984ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.857+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://securetoken.googleapis.com duration=230.130262ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.869+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://google.com duration=242.011428ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.874+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=243.587623ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.890+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=261.410965ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.920+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=292.355747ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.953+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://functions.volumio.cloud duration=324.440306ms Oct 13 10:31:06 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:06.961+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://functions.volumio.cloud duration=330.302427ms Oct 13 10:31:07 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:07.131+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=https://database.volumio.cloud duration=501.648479ms Oct 13 10:31:07 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:07.193+01:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=http://cddb.volumio.org duration=563.539655ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 13 10:31:07 primo-plus volumio[1216]: verbose: New Socket.io Connection to 192.168.4.90 from 192.168.4.108 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: websocket Total Clients: 11 Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 13 10:31:07 primo-plus volumio[1216]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:3OlczsSskkY0qZSzPF2HlC Oct 13 10:31:07 primo-plus volumio[1216]: info: Received Get System Version Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 10:31:07 primo-plus volumio[1216]: info: Received Get System Info Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:31:07 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 13 10:31:07 primo-plus sudo[26011]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 13 10:31:07 primo-plus sudo[26011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:31:07 primo-plus sudo[26016]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:31:07 primo-plus sudo[26016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:31:07 primo-plus sudo[26011]: pam_unix(sudo:session): session closed for user root Oct 13 10:31:07 primo-plus sudo[26016]: pam_unix(sudo:session): session closed for user root Oct 13 10:31:07 primo-plus sudo[26022]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:31:07 primo-plus sudo[26022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:31:07 primo-plus sudo[26029]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:31:07 primo-plus sudo[26029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:31:07 primo-plus volumio[1216]: info: CALLMETHOD: miscellanea novaui getTheme [object Object] Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: novaui , getTheme Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getUpdaterChannel Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:07 primo-plus sudo[26022]: pam_unix(sudo:session): session closed for user root Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetQueue Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreStateMachine::getQueue Oct 13 10:31:07 primo-plus volumio[1216]: info: CorePlayQueue::getQueue Oct 13 10:31:07 primo-plus sudo[26029]: pam_unix(sudo:session): session closed for user root Oct 13 10:31:07 primo-plus sudo[26035]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 13 10:31:07 primo-plus sudo[26035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:31:07 primo-plus sudo[26039]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 13 10:31:07 primo-plus sudo[26039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:31:07 primo-plus sudo[26035]: pam_unix(sudo:session): session closed for user root Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 13 10:31:07 primo-plus volumio[1216]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:3OlczsSskkY0qZSzPF2HlC Oct 13 10:31:07 primo-plus sudo[26039]: pam_unix(sudo:session): session closed for user root Oct 13 10:31:07 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:07 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:07 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:07.480+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=33.288907ms timeout=10s endpoint=http://plugins.volumio.org duration=848.189312ms Oct 13 10:31:07 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:07 primo-plus volumio[1216]: info: Preloading song: spotify:track:3V5xZQOaShEwdNZtrfGJwG Oct 13 10:31:07 primo-plus volumio[1216]: info: Preloading song: spotify:track:6CTVyyHoG2WugpHzeO1M2v Oct 13 10:31:07 primo-plus volumio[1216]: info: Exploding uri spotify:track:3V5xZQOaShEwdNZtrfGJwG in service spop Oct 13 10:31:07 primo-plus volumio[1216]: SPOTIFY: EXPLODING URI:spotify:track:3V5xZQOaShEwdNZtrfGJwG Oct 13 10:31:07 primo-plus volumio[1216]: info: Exploding uri spotify:track:6CTVyyHoG2WugpHzeO1M2v in service spop Oct 13 10:31:07 primo-plus volumio[1216]: SPOTIFY: EXPLODING URI:spotify:track:6CTVyyHoG2WugpHzeO1M2v Oct 13 10:31:08 primo-plus volumio[1216]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3V5xZQOaShEwdNZtrfGJwG","service":"spop","name":"SOUND SYSTEM","artist":"ATYYA","album":"SOUND SYSTEM","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b2735a8062d7a96bdab53983d15c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 10:31:08 primo-plus volumio[1216]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6CTVyyHoG2WugpHzeO1M2v","service":"spop","name":"Holes","artist":"Bliss","album":"Holes","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b273ea0b2bd52976b99118ffacca","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 13 10:31:08 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:31:08 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:31:08 primo-plus volumio[1216]: verbose: New Socket.io Connection to 192.168.4.90:3000 from 192.168.4.108 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12 Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 13 10:31:08 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Oct 13 10:31:11 primo-plus volumio[1216]: info: browseTIDALUri took 313 milliseconds Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 13 10:31:11 primo-plus volumio[1216]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:3OlczsSskkY0qZSzPF2HlC Oct 13 10:31:11 primo-plus volumio[1216]: info: browseTIDALUri took 407 milliseconds Oct 13 10:31:11 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Oct 13 10:31:11 primo-plus volumio[1216]: info: handleBrowseUri took 458 milliseconds Oct 13 10:31:11 primo-plus volumio[1216]: info: handleBrowseUri took 481 milliseconds Oct 13 10:31:12 primo-plus volumio[1216]: info: browseTIDALUri took 158 milliseconds Oct 13 10:31:12 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:13 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:31:13 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:31:16 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:16 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:31:16 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 10:31:16 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:18 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:31:18 primo-plus volumio[1216]: info: Getting BBC Radios Oct 13 10:31:18 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:18 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:31:21 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:21 primo-plus volumio[1216]: info: Spotify Stop Oct 13 10:31:21 primo-plus volumio[1216]: SPOTIFY: SPOTIFY STOP Oct 13 10:31:21 primo-plus volumio[1216]: SPOTIFY: {"status":"pause","title":"Ancestors","artist":"Steak","album":"Acute Mania","albumart":"https://i.scdn.co/image/ab67616d00001e02f3407be1550fdb9f624f348b","uri":"spotify:track:7GGZjRWhtDZwusNFQf0ClL","trackType":"spotify","codec":"ogg","seek":126415,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Oct 13 10:31:21 primo-plus volumio[1216]: info: Sending Spotify command to local API: /player/pause Oct 13 10:31:21 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:31:21 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:21 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:21 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:21 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:21 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_one.m3u8 Oct 13 10:31:21 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:21 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_92079267/live/ww/bbc_1xtra/bbc_1xtra.isml/bbc_1xtra-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://151.80.56.90:8090/bbc_radio_one_dance.aac Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_62063831/live/ww/bbc_radio_one_dance/bbc_radio_one_dance.isml/bbc_radio_one_dance-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_01505109/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_two.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_30624046/live/ww/bbc_radio_three_unwind/bbc_radio_three_unwind.isml/bbc_radio_three_unwind-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio=320000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio=128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::play index 18 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:22 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/uk/mobile_wifi_main_hd_abr_v2/aks/bbc_radio_six_indie_forever.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d48000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_87948813/live/ww/bbc_world_service/bbc_world_service.isml/bbc_world_service-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_31244774/live/ww/bbc_radio_ulster/bbc_radio_ulster.isml/bbc_radio_ulster-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_22108647/live/ww/bbc_asian_network/bbc_asian_network.isml/bbc_asian_network-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: https://vs-hls-push-ww-live.akamaized.net/x=4/i=urn:bbc:pips:service:bbc_news_channel_hd/t=3840/v=pv14/b=5070016/main.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_radio_one.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://stream.live.vc.bbcmedia.co.uk/bbc_world_service Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww.live.cf.md.bbci.co.uk/pool_07364996/live/ww/bbc_world_service_news_internet/bbc_world_service_news_internet.isml/bbc_world_service_news_internet-audio=320000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:22 primo-plus volumio[1216]: info: [1791883882028] ControllerWebradio::stop Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.036+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.037+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 title="BBC Radio 5 Live (128k)" Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:22 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand stop took 43 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 18 Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:31:22 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 18 Oct 13 10:31:22 primo-plus volumio[1216]: info: [1791883882073] ControllerWebradio::clearAddPlayTrack Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:22 primo-plus go-librespot[1878]: time="2026-10-13T10:31:22+01:00" level=debug msg="pause track at 127989ms" Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand stop took 3 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:31:22 primo-plus volumio[1216]: info: Oct 13 10:31:22 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:22 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand clear took 5 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8" Oct 13 10:31:22 primo-plus volumio[1216]: error: updateQueue error: null Oct 13 10:31:22 primo-plus volumio[1216]: info: Oct 13 10:31:22 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:22 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:22 primo-plus volumio[1216]: info: ------------------------------ 13ms Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8" took 10 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:31:22 primo-plus volumio[1216]: info: ------------------------------ 14ms Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand play took 10 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:31:22 primo-plus go-librespot[1878]: time="2026-10-13T10:31:22+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 10:31:22 primo-plus go-librespot[1878]: time="2026-10-13T10:31:22+01:00" level=trace msg="emitting websocket event: paused" Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:5OQQPKEhkzpHjQ6qz9h9X8","uri":"spotify:track:7GGZjRWhtDZwusNFQf0ClL","play_origin":"playlist/ondemand"}} Oct 13 10:31:22 primo-plus volumio[1216]: info: Spotify is playing in volatile mode Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: UNSET VOLATILE Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: {"status":"stop","position":16,"title":"BBC Radio 5 Live (128k)","artist":"","albumart":"https://cdn-radiotime-logos.tunein.com/s24943q.png","uri":"http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8","trackType":"webradio","seek":0,"samplerate":"","bitdepth":"","channels":0,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"webradio","volatile":false,"service":"webradio"} Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: {"status":"pause","service":"spop","title":"Ancestors","artist":"Steak","album":"Acute Mania","albumart":"https://i.scdn.co/image/ab67616d00001e02f3407be1550fdb9f624f348b","uri":"spotify:track:7GGZjRWhtDZwusNFQf0ClL","trackType":"spotify","seek":126415,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.173+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PAUSED positionMs=126415 volume=100 Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.175+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=spotify:track:7GGZjRWhtDZwusNFQf0ClL title=Ancestors Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:22 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:22 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:22 primo-plus go-librespot[1878]: time="2026-10-13T10:31:22+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 10:31:22 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: Executing endpoint metavolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 13 10:31:22 primo-plus volumio[1216]: info: Oct 13 10:31:22 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:22 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:22 primo-plus volumio[1216]: info: Oct 13 10:31:22 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand status took 12 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand status took 7 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:22 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.497+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.498+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 title=bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: ------------------------------ 46ms Oct 13 10:31:22 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 13 10:31:22 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:22 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:22 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:22 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.512+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=1230 volume=100 Oct 13 10:31:22 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:22.513+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 title=bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:22 primo-plus volumio[1216]: info: ------------------------------ 47ms Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:22 primo-plus volumio[1216]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:22 primo-plus volumio[1216]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 13 10:31:22 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:22 primo-plus volumio[1216]: error: Failed to parse state for serial connection: TypeError: Cannot read properties of undefined (reading 'toUpperCase') Oct 13 10:31:22 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:22 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:22 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:22 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:22 primo-plus volumio[1216]: info: MCU Signalled Playback Active Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 13 10:31:22 primo-plus volumio[1216]: info: camilladsp stopping service pid 25990... Oct 13 10:31:22 primo-plus volumio[1216]: grep: /proc/25990/cmdline: binary file matches Oct 13 10:31:22 primo-plus volumio[1216]: info: camilladsp service terminated, instance 1 Oct 13 10:31:22 primo-plus volumio[1216]: error: FusionDsp - File size not found in array! Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Nulleq applied Oct 13 10:31:22 primo-plus volumio[1216]: info: camilladsp service started and running in background, instance 1 Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 2000ms Oct 13 10:31:22 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 4000ms Oct 13 10:31:22 primo-plus volumio[1216]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 13 10:31:24 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:30 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:30 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:33 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:33 primo-plus volumio[1216]: info: ControllerMpd::stop Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:33 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_one.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_92079267/live/ww/bbc_1xtra/bbc_1xtra.isml/bbc_1xtra-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://151.80.56.90:8090/bbc_radio_one_dance.aac Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_62063831/live/ww/bbc_radio_one_dance/bbc_radio_one_dance.isml/bbc_radio_one_dance-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_01505109/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_two.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_30624046/live/ww/bbc_radio_three_unwind/bbc_radio_three_unwind.isml/bbc_radio_three_unwind-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio=320000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio=128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::play index 17 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:33 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/uk/mobile_wifi_main_hd_abr_v2/aks/bbc_radio_six_indie_forever.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d48000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_87948813/live/ww/bbc_world_service/bbc_world_service.isml/bbc_world_service-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_31244774/live/ww/bbc_radio_ulster/bbc_radio_ulster.isml/bbc_radio_ulster-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_22108647/live/ww/bbc_asian_network/bbc_asian_network.isml/bbc_asian_network-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: https://vs-hls-push-ww-live.akamaized.net/x=4/i=urn:bbc:pips:service:bbc_news_channel_hd/t=3840/v=pv14/b=5070016/main.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_radio_one.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://stream.live.vc.bbcmedia.co.uk/bbc_world_service Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww.live.cf.md.bbci.co.uk/pool_07364996/live/ww/bbc_world_service_news_internet/bbc_world_service_news_internet.isml/bbc_world_service_news_internet-audio=320000.norewind.m3u8 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 18 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 18 Oct 13 10:31:33 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:33 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 18 Oct 13 10:31:33 primo-plus volumio[1216]: info: ControllerMpd::stop Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:33 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:33.859+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:33 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:33.861+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id= title= Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:33 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:33 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:33 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:33 primo-plus volumio[1216]: info: Oct 13 10:31:33 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand stop took 85 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand stop took 41 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:33 primo-plus volumio[1216]: info: [1791883893898] ControllerWebradio::clearAddPlayTrack Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand status took 6 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand stop took 5 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:31:33 primo-plus volumio[1216]: info: Oct 13 10:31:33 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:33 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand clear took 8 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8" Oct 13 10:31:33 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:33 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:33 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:33 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:33 primo-plus volumio[1216]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 13 10:31:33 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:33.930+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:33 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:33.931+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:31:33 primo-plus volumio[1216]: info: ------------------------------ 39ms Oct 13 10:31:33 primo-plus volumio[1216]: error: updateQueue error: null Oct 13 10:31:33 primo-plus volumio[1216]: info: Oct 13 10:31:33 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:33 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:33 primo-plus volumio[1216]: info: ------------------------------ 29ms Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8" took 27 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:31:33 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:31:33 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:31:33 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:33 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:33 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:33 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:33 primo-plus volumio[1216]: info: ------------------------------ 19ms Oct 13 10:31:33 primo-plus volumio[1216]: info: sendMpdCommand play took 18 milliseconds Oct 13 10:31:33 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: last_100 , handleBrowseUri Oct 13 10:31:34 primo-plus volumio[1216]: info: Oct 13 10:31:34 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:34 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:34 primo-plus volumio[1216]: info: Oct 13 10:31:34 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:34 primo-plus volumio[1216]: info: sendMpdCommand status took 8 milliseconds Oct 13 10:31:34 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:34 primo-plus volumio[1216]: info: sendMpdCommand status took 4 milliseconds Oct 13 10:31:34 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:34 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:34 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_6music-audio%3d320000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:34 primo-plus volumio[1216]: verbose: CURRENT POSITION 17 Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus stop Oct 13 10:31:34 primo-plus volumio[1216]: info: ------------------------------ 17ms Oct 13 10:31:34 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:31:34 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:34 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:34 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_6music-audio%3d320000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:34 primo-plus volumio[1216]: verbose: CURRENT POSITION 17 Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:31:34 primo-plus volumio[1216]: info: Received an update from plugin. extracting info from payload Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:34 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:34 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:34 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:34 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:34 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:34.064+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:34 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:34.065+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:31:34 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:34.066+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:34 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:34.066+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:31:34 primo-plus volumio[1216]: info: ------------------------------ 45ms Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:34 primo-plus volumio[1216]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:34 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:34 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:34 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:34 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:34 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:34 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:34 primo-plus volumio[1216]: info: MCU Signalled Playback Active Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 13 10:31:34 primo-plus volumio[1216]: error: FusionDsp - File size not found in array! Oct 13 10:31:34 primo-plus volumio[1216]: info: FusionDsp - Nulleq applied Oct 13 10:31:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 10:31:40 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:41 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:31:41 primo-plus volumio[1216]: info: Getting BBC Radios Oct 13 10:31:41 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:43 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:43 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:43 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:43 primo-plus volumio[1216]: info: [1791883903376] ControllerWebradio::stop Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:43 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_one.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_92079267/live/ww/bbc_1xtra/bbc_1xtra.isml/bbc_1xtra-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://151.80.56.90:8090/bbc_radio_one_dance.aac Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_62063831/live/ww/bbc_radio_one_dance/bbc_radio_one_dance.isml/bbc_radio_one_dance-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_01505109/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_two.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_30624046/live/ww/bbc_radio_three_unwind/bbc_radio_three_unwind.isml/bbc_radio_three_unwind-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio=320000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio=128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:43.388+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:43 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:43.389+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::play index 16 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:43 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/uk/mobile_wifi_main_hd_abr_v2/aks/bbc_radio_six_indie_forever.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d48000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_87948813/live/ww/bbc_world_service/bbc_world_service.isml/bbc_world_service-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_31244774/live/ww/bbc_radio_ulster/bbc_radio_ulster.isml/bbc_radio_ulster-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_22108647/live/ww/bbc_asian_network/bbc_asian_network.isml/bbc_asian_network-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: https://vs-hls-push-ww-live.akamaized.net/x=4/i=urn:bbc:pips:service:bbc_news_channel_hd/t=3840/v=pv14/b=5070016/main.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_radio_one.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://stream.live.vc.bbcmedia.co.uk/bbc_world_service Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww.live.cf.md.bbci.co.uk/pool_07364996/live/ww/bbc_world_service_news_internet/bbc_world_service_news_internet.isml/bbc_world_service_news_internet-audio=320000.norewind.m3u8 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 10:31:43 primo-plus volumio[1216]: info: [1791883903410] ControllerWebradio::clearAddPlayTrack Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:43 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:43 primo-plus volumio[1216]: info: Oct 13 10:31:43 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand stop took 70 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand stop took 35 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:31:43 primo-plus volumio[1216]: info: Oct 13 10:31:43 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:43 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand status took 5 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand clear took 3 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8" Oct 13 10:31:43 primo-plus volumio[1216]: error: updateQueue error: null Oct 13 10:31:43 primo-plus volumio[1216]: info: Oct 13 10:31:43 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:43 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:43 primo-plus volumio[1216]: info: ------------------------------ 6ms Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8" took 5 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:31:43 primo-plus volumio[1216]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 13 10:31:43 primo-plus volumio[1216]: info: ------------------------------ 14ms Oct 13 10:31:43 primo-plus volumio[1216]: info: ------------------------------ 8ms Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand play took 6 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:31:43 primo-plus volumio[1216]: info: Oct 13 10:31:43 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:43 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:43 primo-plus volumio[1216]: info: Oct 13 10:31:43 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand status took 3 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand status took 4 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:43 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:43 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_five_live-audio%3d128000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:43 primo-plus volumio[1216]: verbose: CURRENT POSITION 16 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus stop Oct 13 10:31:43 primo-plus volumio[1216]: info: ------------------------------ 10ms Oct 13 10:31:43 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:31:43 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:43 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:43 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1230,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_five_live-audio%3d128000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:43 primo-plus volumio[1216]: verbose: CURRENT POSITION 16 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:31:43 primo-plus volumio[1216]: info: Received an update from plugin. extracting info from payload Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:43 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:43 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:43 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:43 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:43 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:43 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:43.594+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:43 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:43.595+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 title="BBC Radio 5 Live (128k)" Oct 13 10:31:43 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:43.596+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:43 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:43.596+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 title="BBC Radio 5 Live (128k)" Oct 13 10:31:43 primo-plus volumio[1216]: info: ------------------------------ 30ms Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:43 primo-plus volumio[1216]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:43 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:43 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:43 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:43 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:43 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:43 primo-plus volumio[1216]: info: MCU Signalled Playback Active Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 13 10:31:43 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 13 10:31:44 primo-plus volumio[1216]: error: FusionDsp - File size not found in array! Oct 13 10:31:44 primo-plus volumio[1216]: info: FusionDsp - Nulleq applied Oct 13 10:31:44 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 8000ms Oct 13 10:31:44 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 16000ms Oct 13 10:31:44 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms Oct 13 10:31:44 primo-plus volumio[1216]: info: camilladsp respawn in 200 ms (attempt 2/10) Oct 13 10:31:45 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:45 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:45 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:45 primo-plus volumio[1216]: info: [1791883905786] ControllerWebradio::stop Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:45 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_one.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_92079267/live/ww/bbc_1xtra/bbc_1xtra.isml/bbc_1xtra-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://151.80.56.90:8090/bbc_radio_one_dance.aac Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_62063831/live/ww/bbc_radio_one_dance/bbc_radio_one_dance.isml/bbc_radio_one_dance-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_01505109/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_two.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_30624046/live/ww/bbc_radio_three_unwind/bbc_radio_three_unwind.isml/bbc_radio_three_unwind-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio=320000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio=128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:45.799+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:45 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:45.799+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 title="BBC Radio 5 Live (128k)" Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 16 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::play index 15 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:45 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/uk/mobile_wifi_main_hd_abr_v2/aks/bbc_radio_six_indie_forever.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d48000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_87948813/live/ww/bbc_world_service/bbc_world_service.isml/bbc_world_service-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_31244774/live/ww/bbc_radio_ulster/bbc_radio_ulster.isml/bbc_radio_ulster-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_22108647/live/ww/bbc_asian_network/bbc_asian_network.isml/bbc_asian_network-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: https://vs-hls-push-ww-live.akamaized.net/x=4/i=urn:bbc:pips:service:bbc_news_channel_hd/t=3840/v=pv14/b=5070016/main.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_radio_one.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://stream.live.vc.bbcmedia.co.uk/bbc_world_service Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww.live.cf.md.bbci.co.uk/pool_07364996/live/ww/bbc_world_service_news_internet/bbc_world_service_news_internet.isml/bbc_world_service_news_internet-audio=320000.norewind.m3u8 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 10:31:45 primo-plus volumio[1216]: info: [1791883905842] ControllerWebradio::clearAddPlayTrack Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:45 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:45 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:45 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:45 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:45 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:45 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:45 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:45 primo-plus volumio[1216]: info: Oct 13 10:31:45 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand stop took 99 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand stop took 44 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:31:45 primo-plus volumio[1216]: info: Oct 13 10:31:45 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:45 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand status took 4 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand clear took 3 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8" Oct 13 10:31:45 primo-plus volumio[1216]: error: updateQueue error: null Oct 13 10:31:45 primo-plus volumio[1216]: info: Oct 13 10:31:45 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:45 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:45 primo-plus volumio[1216]: info: ------------------------------ 7ms Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8" took 6 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:31:45 primo-plus volumio[1216]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 13 10:31:45 primo-plus volumio[1216]: info: ------------------------------ 13ms Oct 13 10:31:45 primo-plus volumio[1216]: info: ------------------------------ 5ms Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand play took 3 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:31:45 primo-plus volumio[1216]: info: Oct 13 10:31:45 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:45 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:45 primo-plus volumio[1216]: info: Oct 13 10:31:45 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand status took 4 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand status took 1 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:45 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:45 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_four_extra-audio=320000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:45 primo-plus volumio[1216]: verbose: CURRENT POSITION 15 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus stop Oct 13 10:31:45 primo-plus volumio[1216]: info: ------------------------------ 11ms Oct 13 10:31:45 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 13 10:31:45 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:45 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:45 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_four_extra-audio=320000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:45 primo-plus volumio[1216]: verbose: CURRENT POSITION 15 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:31:45 primo-plus volumio[1216]: info: Received an update from plugin. extracting info from payload Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:46 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:46 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:46 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:46 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:46 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:46 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:46 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:46 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:46 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:46.015+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:46 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:46.016+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id="http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8" title="BBC Radio 4 Extra" Oct 13 10:31:46 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:46.019+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:46 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:46.019+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id="http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8" title="BBC Radio 4 Extra" Oct 13 10:31:46 primo-plus volumio[1216]: info: ------------------------------ 42ms Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:46 primo-plus volumio[1216]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:46 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:46 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:46 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:46 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:46 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:46 primo-plus volumio[1216]: info: MCU Signalled Playback Active Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 13 10:31:46 primo-plus volumio[1216]: error: FusionDsp - File size not found in array! Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Nulleq applied Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms Oct 13 10:31:46 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms Oct 13 10:31:46 primo-plus volumio[1216]: info: camilladsp respawn in 400 ms (attempt 3/10) Oct 13 10:31:52 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:52 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:52 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:52 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:52 primo-plus volumio[1216]: info: [1791883912611] ControllerWebradio::stop Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:52 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_one.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_92079267/live/ww/bbc_1xtra/bbc_1xtra.isml/bbc_1xtra-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://151.80.56.90:8090/bbc_radio_one_dance.aac Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_62063831/live/ww/bbc_radio_one_dance/bbc_radio_one_dance.isml/bbc_radio_one_dance-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:52.620+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:52 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:52.620+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id="http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8" title="BBC Radio 4 Extra" Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 15 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::play index 5 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:52 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_01505109/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_two.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_30624046/live/ww/bbc_radio_three_unwind/bbc_radio_three_unwind.isml/bbc_radio_three_unwind-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio=320000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio=128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/uk/mobile_wifi_main_hd_abr_v2/aks/bbc_radio_six_indie_forever.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d48000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_87948813/live/ww/bbc_world_service/bbc_world_service.isml/bbc_world_service-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_31244774/live/ww/bbc_radio_ulster/bbc_radio_ulster.isml/bbc_radio_ulster-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_22108647/live/ww/bbc_asian_network/bbc_asian_network.isml/bbc_asian_network-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: https://vs-hls-push-ww-live.akamaized.net/x=4/i=urn:bbc:pips:service:bbc_news_channel_hd/t=3840/v=pv14/b=5070016/main.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_radio_one.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://stream.live.vc.bbcmedia.co.uk/bbc_world_service Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww.live.cf.md.bbci.co.uk/pool_07364996/live/ww/bbc_world_service_news_internet/bbc_world_service_news_internet.isml/bbc_world_service_news_internet-audio=320000.norewind.m3u8 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 10:31:52 primo-plus volumio[1216]: info: [1791883912646] ControllerWebradio::clearAddPlayTrack Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:52 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:52 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:52 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:52 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:52 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:52 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:52 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:52 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:52 primo-plus volumio[1216]: info: Oct 13 10:31:52 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand stop took 66 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand stop took 30 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:31:52 primo-plus volumio[1216]: info: Oct 13 10:31:52 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:52 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand status took 5 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand clear took 4 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand add "https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8" Oct 13 10:31:52 primo-plus volumio[1216]: error: updateQueue error: null Oct 13 10:31:52 primo-plus volumio[1216]: info: Oct 13 10:31:52 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:52 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:52 primo-plus volumio[1216]: info: ------------------------------ 4ms Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand add "https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8" took 4 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:52 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:31:52 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:31:52 primo-plus volumio[1216]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 13 10:31:52 primo-plus volumio[1216]: info: ------------------------------ 11ms Oct 13 10:31:52 primo-plus volumio[1216]: info: ------------------------------ 6ms Oct 13 10:31:52 primo-plus volumio[1216]: info: sendMpdCommand play took 5 milliseconds Oct 13 10:31:52 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:31:53 primo-plus volumio[1216]: info: Oct 13 10:31:53 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:53 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:53 primo-plus volumio[1216]: info: Oct 13 10:31:53 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:53 primo-plus volumio[1216]: info: sendMpdCommand status took 3 milliseconds Oct 13 10:31:53 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:53 primo-plus volumio[1216]: info: sendMpdCommand status took 2 milliseconds Oct 13 10:31:53 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:53 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:53 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_1xtra.m3u8","artist":null,"album":null,"uri":"https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8","trackType":"m3u8"} Oct 13 10:31:53 primo-plus volumio[1216]: verbose: CURRENT POSITION 5 Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus stop Oct 13 10:31:53 primo-plus volumio[1216]: info: ------------------------------ 8ms Oct 13 10:31:53 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 13 10:31:53 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:53 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:53 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_1xtra.m3u8","artist":null,"album":null,"uri":"https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8","trackType":"m3u8"} Oct 13 10:31:53 primo-plus volumio[1216]: verbose: CURRENT POSITION 5 Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:31:53 primo-plus volumio[1216]: info: Received an update from plugin. extracting info from payload Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:53 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:53 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:53 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:53 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:53 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:53 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:53.333+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:53 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:53.333+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:53 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:53.334+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 title=" BBC RADIO 1XTRA: Amplifying black music & culture" Oct 13 10:31:53 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:53.334+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 title=" BBC RADIO 1XTRA: Amplifying black music & culture" Oct 13 10:31:53 primo-plus volumio[1216]: info: ------------------------------ 32ms Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:53 primo-plus volumio[1216]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:53 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:53 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:53 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:53 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:53 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:53 primo-plus volumio[1216]: error: FusionDsp - Monitor WebSocket error: [object Object] Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms Oct 13 10:31:53 primo-plus volumio[1216]: error: FusionDsp - Monitor WebSocket error: [object Object] Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms Oct 13 10:31:53 primo-plus volumio[1216]: info: camilladsp respawn in 800 ms (attempt 4/10) Oct 13 10:31:53 primo-plus volumio[1216]: info: MCU Signalled Playback Active Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 13 10:31:53 primo-plus volumio[1216]: error: FusionDsp - File size not found in array! Oct 13 10:31:53 primo-plus volumio[1216]: info: FusionDsp - Nulleq applied Oct 13 10:31:53 primo-plus volumio[1216]: error: FusionDsp - Reload WebSocket error: [object Object] Oct 13 10:31:56 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:56 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:56 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:31:56 primo-plus volumio[1216]: info: [1791883916810] ControllerWebradio::stop Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:56 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/ak/bbc_radio_one.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_one.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_92079267/live/ww/bbc_1xtra/bbc_1xtra.isml/bbc_1xtra-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://151.80.56.90:8090/bbc_radio_one_dance.aac Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_62063831/live/ww/bbc_radio_one_dance/bbc_radio_one_dance.isml/bbc_radio_one_dance-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_01505109/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/pc_hd_abr_v2/cf/bbc_radio_two.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_30624046/live/ww/bbc_radio_three_unwind/bbc_radio_three_unwind.isml/bbc_radio_three_unwind-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio=320000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_55057080/live/ww/bbc_radio_fourfm/bbc_radio_fourfm.isml/bbc_radio_fourfm-audio=128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_26173715/live/ww/bbc_radio_four_extra/bbc_radio_four_extra.isml/bbc_radio_four_extra-audio=320000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_89021708/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:56.822+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:31:56 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:56.823+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_1xtra.m3u8 title=" BBC RADIO 1XTRA: Amplifying black music & culture" Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 5 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::play index 17 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:31:56 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/uk/mobile_wifi_main_hd_abr_v2/aks/bbc_radio_six_indie_forever.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d48000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_53367543/live/ww/bbc_sounds_news/bbc_sounds_news.isml/bbc_sounds_news-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_87948813/live/ww/bbc_world_service/bbc_world_service.isml/bbc_world_service-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_31244774/live/ww/bbc_radio_ulster/bbc_radio_ulster.isml/bbc_radio_ulster-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_22108647/live/ww/bbc_asian_network/bbc_asian_network.isml/bbc_asian_network-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: https://vs-hls-push-ww-live.akamaized.net/x=4/i=urn:bbc:pips:service:bbc_news_channel_hd/t=3840/v=pv14/b=5070016/main.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: https://stream.live.vc.bbcmedia.co.uk/bbc_arabic_radio Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: https://a.files.bbci.co.uk/ms6/live/3441A116-B12E-4D2F-ACA8-C1984642FA4B/audio/simulcast/hls/nonuk/audio_syndication_low_sbr_v1/aks/bbc_radio_one.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_43322914/live/ww/bbc_radio_scotland_fm/bbc_radio_scotland_fm.isml/bbc_radio_scotland_fm-audio%3d128000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://stream.live.vc.bbcmedia.co.uk/bbc_world_service Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: Adding Item to queue: http://as-hls-ww.live.cf.md.bbci.co.uk/pool_07364996/live/ww/bbc_world_service_news_internet/bbc_world_service_news_internet.isml/bbc_world_service_news_internet-audio=320000.norewind.m3u8 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 10:31:56 primo-plus volumio[1216]: info: [1791883916848] ControllerWebradio::clearAddPlayTrack Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:31:56 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:31:56 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:31:56 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:56 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:56 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:56 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:56 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:56 primo-plus volumio[1216]: info: Oct 13 10:31:56 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand stop took 81 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand stop took 44 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:31:56 primo-plus volumio[1216]: info: Oct 13 10:31:56 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:56 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand status took 5 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand clear took 5 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8" Oct 13 10:31:56 primo-plus volumio[1216]: error: updateQueue error: null Oct 13 10:31:56 primo-plus volumio[1216]: info: Oct 13 10:31:56 primo-plus volumio[1216]: ---------------------------- MPD announces system playlist update Oct 13 10:31:56 primo-plus volumio[1216]: info: Ignoring MPD Status Update Oct 13 10:31:56 primo-plus volumio[1216]: info: ------------------------------ 8ms Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8" took 7 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:31:56 primo-plus volumio[1216]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 13 10:31:56 primo-plus volumio[1216]: info: ------------------------------ 15ms Oct 13 10:31:56 primo-plus volumio[1216]: info: ------------------------------ 4ms Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand play took 3 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:31:56 primo-plus volumio[1216]: info: Oct 13 10:31:56 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:56 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:56 primo-plus volumio[1216]: info: Oct 13 10:31:56 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand status took 4 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand status took 1 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:56 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:56 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_6music-audio%3d320000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:56 primo-plus volumio[1216]: verbose: CURRENT POSITION 17 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus stop Oct 13 10:31:56 primo-plus volumio[1216]: info: ------------------------------ 8ms Oct 13 10:31:56 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 13 10:31:56 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:31:56 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:56 primo-plus volumio[1216]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_6music-audio%3d320000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8","trackType":"m3u8"} Oct 13 10:31:56 primo-plus volumio[1216]: verbose: CURRENT POSITION 17 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::syncState stateService play Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:31:56 primo-plus volumio[1216]: info: Received an update from plugin. extracting info from payload Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:56 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:56 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:31:56 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:31:56 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:31:57 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:31:57 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:57.008+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:57 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:57.009+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:31:57 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:57.009+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:31:57 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:31:57.009+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:31:57 primo-plus volumio[1216]: info: ------------------------------ 29ms Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:57 primo-plus volumio[1216]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - Volumio is playing Oct 13 10:31:57 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:57 primo-plus volumio[1216]: info: Signalling Playback active due to playback status change Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:31:57 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:31:57 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:57 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - Clipping Monitor started Oct 13 10:31:57 primo-plus volumio[1216]: info: MCU Signalled Playback Active Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 13 10:31:57 primo-plus volumio[1216]: error: FusionDsp - File size not found in array! Oct 13 10:31:57 primo-plus volumio[1216]: info: FusionDsp - Nulleq applied Oct 13 10:32:04 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.365+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.4.108:53866 @ 0x2b60570" latency=31.332783ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.377+01:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.386+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=8.654277ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.401+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=http://pushupdates.volumio.org duration=22.079527ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.402+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=22.877958ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.406+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=27.44449ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.420+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://google.com duration=41.947037ms Oct 13 10:32:12 primo-plus volumio[1216]: verbose: New Socket.io Connection to 192.168.4.90 from 192.168.4.108 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: websocket Total Clients: 12 Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.483+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=104.727253ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.485+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://www.googleapis.com duration=106.414817ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.492+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://securetoken.googleapis.com duration=114.306662ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.498+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://functions.volumio.cloud duration=119.772679ms Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.512+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://functions.volumio.cloud duration=134.081266ms Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:32:12 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.535+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=https://database.volumio.cloud duration=156.784523ms Oct 13 10:32:12 primo-plus volumio[1216]: verbose: New Socket.io Connection to 192.168.4.90 from 192.168.4.108 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: websocket Total Clients: 10 Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetQueue Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreStateMachine::getQueue Oct 13 10:32:12 primo-plus volumio[1216]: info: CorePlayQueue::getQueue Oct 13 10:32:12 primo-plus volumio[1216]: info: Received Get System Version Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 10:32:12 primo-plus volumio[1216]: info: Received Get System Info Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:32:12 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getUpdaterChannel Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 13 10:32:12 primo-plus volumio[1216]: info: CALLMETHOD: miscellanea novaui getTheme [object Object] Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: novaui , getTheme Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 13 10:32:12 primo-plus sudo[26345]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 13 10:32:12 primo-plus sudo[26345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:12 primo-plus sudo[26345]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:12 primo-plus sudo[26350]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:32:12 primo-plus sudo[26350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:12 primo-plus sudo[26357]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:32:12 primo-plus sudo[26357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:12 primo-plus sudo[26350]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:12 primo-plus sudo[26357]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 13 10:32:12 primo-plus volumio[1216]: info: Received Get System Version Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 10:32:12 primo-plus volumio[1216]: info: Received Get System Info Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:32:12 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 10:32:12 primo-plus sudo[26369]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 13 10:32:12 primo-plus sudo[26363]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:32:12 primo-plus sudo[26369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:12 primo-plus sudo[26363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetQueue Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreStateMachine::getQueue Oct 13 10:32:12 primo-plus volumio[1216]: info: CorePlayQueue::getQueue Oct 13 10:32:12 primo-plus sudo[26369]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:32:12 primo-plus volumio[1216]: info: Getting BBC Radios Oct 13 10:32:12 primo-plus sudo[26363]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:32:12 primo-plus volumio[1216]: info: Getting BBC Radios Oct 13 10:32:12 primo-plus sudo[26372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 13 10:32:12 primo-plus sudo[26372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:12 primo-plus sudo[26372]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 10:32:12 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 10:32:12 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:12.938+01:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=http://cddb.volumio.org duration=560.096415ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 13 10:32:13 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:13.085+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=25.674462ms timeout=10s endpoint=http://plugins.volumio.org duration=705.869091ms Oct 13 10:32:13 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 10:32:13 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:13 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:13 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:32:20 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:20 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:28 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:28 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:30 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::volumioStop Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:35 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:32:35 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::serviceStop Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::serviceStop Oct 13 10:32:35 primo-plus volumio[1216]: info: [1791883955550] ControllerWebradio::stop Oct 13 10:32:35 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:32:35 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:35.555+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:32:35 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:35.555+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:32:35 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:32:35 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:32:35 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:32:35 primo-plus volumio[1216]: info: Oct 13 10:32:35 primo-plus volumio[1216]: ---------------------------- MPD announces state update: player Oct 13 10:32:35 primo-plus volumio[1216]: info: sendMpdCommand stop took 26 milliseconds Oct 13 10:32:35 primo-plus volumio[1216]: info: ControllerMpd::getState Oct 13 10:32:35 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:32:35 primo-plus volumio[1216]: info: sendMpdCommand status took 7 milliseconds Oct 13 10:32:35 primo-plus volumio[1216]: verbose: ControllerMpd::parseState Oct 13 10:32:35 primo-plus volumio[1216]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:32:35 primo-plus volumio[1216]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 13 10:32:35 primo-plus volumio[1216]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:32:35 primo-plus volumio[1216]: info: ControllerMpd::pushState Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::servicePushState Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreStateMachine::pushState Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushState Oct 13 10:32:35 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:35 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:32:35 primo-plus volumio[1216]: info: MRS: Pushing multiroomSync output Oct 13 10:32:35 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:35 primo-plus volumio[1216]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 13 10:32:35 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:35.595+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:32:35 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:35.597+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.108:53866 @ 0x2b60570" id=http://as-hls-ww-live.akamaized.net/pool_81827798/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 title="BBC Radio 6 Music" Oct 13 10:32:35 primo-plus volumio[1216]: info: ------------------------------ 24ms Oct 13 10:32:35 primo-plus volumio[1216]: info: FusionDsp - Volumio is not playing Oct 13 10:32:35 primo-plus volumio[1216]: info: FusionDsp - Clipped samples monitor stopped Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: SPOTIFY VOLUME 99 Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: VOLUMIO VOLUME 100 Oct 13 10:32:35 primo-plus volumio[1216]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 10:32:35 primo-plus volumio[1216]: info: Updating RAAT Signal Path Oct 13 10:32:35 primo-plus volumio[1216]: info: MCU Signalled Playback Inactive Oct 13 10:32:36 primo-plus volumio[1216]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.198+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.4.108:53866 @ 0x2b60570" latency=26.736842ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.213+01:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.222+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=8.489742ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.235+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=21.717589ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.238+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=24.573614ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.239+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=http://pushupdates.volumio.org duration=24.285527ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.265+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://google.com duration=51.408004ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.318+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=104.394036ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.322+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://www.googleapis.com duration=107.799811ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.325+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://securetoken.googleapis.com duration=111.443378ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.349+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://functions.volumio.cloud duration=134.691774ms Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.349+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://functions.volumio.cloud duration=135.349077ms Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:32:38 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:32:38 primo-plus volumio[1216]: verbose: New Socket.io Connection to 192.168.4.90 from 192.168.4.108 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: websocket Total Clients: 10 Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetQueue Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreStateMachine::getQueue Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getQueue Oct 13 10:32:38 primo-plus volumio[1216]: info: Received Get System Version Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 10:32:38 primo-plus volumio[1216]: info: Received Get System Info Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:32:38 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getUpdaterChannel Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 13 10:32:38 primo-plus volumio[1216]: info: CALLMETHOD: miscellanea novaui getTheme [object Object] Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: novaui , getTheme Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 13 10:32:38 primo-plus sudo[26474]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 13 10:32:38 primo-plus sudo[26474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:38 primo-plus sudo[26474]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:38 primo-plus sudo[26479]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:32:38 primo-plus sudo[26479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:38 primo-plus sudo[26479]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.471+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=https://database.volumio.cloud duration=256.685859ms Oct 13 10:32:38 primo-plus sudo[26486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:32:38 primo-plus sudo[26486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 13 10:32:38 primo-plus volumio[1216]: info: Received Get System Version Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 10:32:38 primo-plus volumio[1216]: info: Received Get System Info Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 10:32:38 primo-plus volumio[1216]: info: Discovery: Getting this device information Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 10:32:38 primo-plus sudo[26486]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetQueue Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreStateMachine::getQueue Oct 13 10:32:38 primo-plus volumio[1216]: info: CorePlayQueue::getQueue Oct 13 10:32:38 primo-plus sudo[26492]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 13 10:32:38 primo-plus sudo[26492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:38 primo-plus sudo[26498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 13 10:32:38 primo-plus sudo[26498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:38 primo-plus sudo[26498]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:38 primo-plus sudo[26492]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:38 primo-plus sudo[26501]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 13 10:32:38 primo-plus sudo[26501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 10:32:38 primo-plus sudo[26501]: pam_unix(sudo:session): session closed for user root Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 10:32:38 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.812+01:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=http://cddb.volumio.org duration=597.779728ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 13 10:32:38 primo-plus volumio5-onboarding[2587]: time=2026-10-13T10:32:38.866+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.108:53866 @ 0x2b60570" latency=24.997846ms timeout=10s endpoint=http://plugins.volumio.org duration=651.710522ms Oct 13 10:32:39 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:32:39 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:32:41 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Oct 13 10:32:42 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:42 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:43 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:45 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:32:45 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D0%22%2C%22name%22%3A%22The%20Main%20Mix%22%2C%22title%22%3A%22The%20Main%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F0%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D0%22%2C%22name%22%3A%22The%20Main%20Mix%22%2C%22title%22%3A%22The%20Main%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F0%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 17 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::play index 0 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:32:45 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D1%22%2C%22name%22%3A%22Mellow%20Mix%22%2C%22title%22%3A%22Mellow%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F1%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D1%22%2C%22name%22%3A%22Mellow%20Mix%22%2C%22title%22%3A%22Mellow%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F1%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D2%22%2C%22name%22%3A%22RockIt!%22%2C%22title%22%3A%22RockIt!%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F2%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D2%22%2C%22name%22%3A%22RockIt!%22%2C%22title%22%3A%22RockIt!%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F2%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D3%22%2C%22name%22%3A%22The%20Globe%22%2C%22title%22%3A%22The%20Globe%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F3%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D3%22%2C%22name%22%3A%22The%20Globe%22%2C%22title%22%3A%22The%20Globe%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F3%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D5%22%2C%22name%22%3A%22Beyond...%22%2C%22title%22%3A%22Beyond...%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F5%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D5%22%2C%22name%22%3A%22Beyond...%22%2C%22title%22%3A%22Beyond...%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F5%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D11%22%2C%22name%22%3A%22Sanctuary%22%2C%22title%22%3A%22Sanctuary%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F11%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D11%22%2C%22name%22%3A%22Sanctuary%22%2C%22title%22%3A%22Sanctuary%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F11%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:45 primo-plus volumio[1216]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 0 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 0 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 10:32:45 primo-plus volumio[1216]: info: [rp2] clearAddPlayTrack: rp2/channel@id=0 Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:32:45 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:32:45 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:32:51 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::ClearQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::clearPlayQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:32:51 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D0%22%2C%22name%22%3A%22The%20Main%20Mix%22%2C%22title%22%3A%22The%20Main%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F0%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D0%22%2C%22name%22%3A%22The%20Main%20Mix%22%2C%22title%22%3A%22The%20Main%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F0%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::volumioGetState Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 0 Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPlay Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::play index 0 Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::addQueueItems Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::addQueueItems Oct 13 10:32:51 primo-plus volumio[1216]: info: Preload queue cleared Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D1%22%2C%22name%22%3A%22Mellow%20Mix%22%2C%22title%22%3A%22Mellow%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F1%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D1%22%2C%22name%22%3A%22Mellow%20Mix%22%2C%22title%22%3A%22Mellow%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F1%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D2%22%2C%22name%22%3A%22RockIt!%22%2C%22title%22%3A%22RockIt!%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F2%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D2%22%2C%22name%22%3A%22RockIt!%22%2C%22title%22%3A%22RockIt!%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F2%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D3%22%2C%22name%22%3A%22The%20Globe%22%2C%22title%22%3A%22The%20Globe%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F3%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D3%22%2C%22name%22%3A%22The%20Globe%22%2C%22title%22%3A%22The%20Globe%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F3%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D5%22%2C%22name%22%3A%22Beyond...%22%2C%22title%22%3A%22Beyond...%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F5%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D5%22%2C%22name%22%3A%22Beyond...%22%2C%22title%22%3A%22Beyond...%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F5%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D11%22%2C%22name%22%3A%22Sanctuary%22%2C%22title%22%3A%22Sanctuary%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F11%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D11%22%2C%22name%22%3A%22Sanctuary%22%2C%22title%22%3A%22Sanctuary%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F11%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::stop Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::saveQueue Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::play index undefined Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::updateTrackBlock Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::getTrackBlock Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 0 Oct 13 10:32:51 primo-plus volumio[1216]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:32:51 primo-plus volumio[1216]: info: CorePlayQueue::getTrack 0 Oct 13 10:32:51 primo-plus volumio[1216]: info: [rp2] clearAddPlayTrack: rp2/channel@id=0 Oct 13 10:32:51 primo-plus volumio[1216]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=0&audio_type= Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Obtained block for channel "0" Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] ------------- Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Block summary Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] ------------- Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Stream URL: https://audio.radioparadise.stream/audio/blocks/0/x/1476/4/b/1476-0.flac Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Tracks: Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] 0. Sail (4:14 | elapsed: 21m 2s) Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] 1. Something in the Water (3:42 | elapsed: 25m 17s) Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Oct 13 10:32:52 primo-plus volumio[1216]: verbose: [rp2] Current track scheduled playback vs. current time: 10/13/2026, 10:32:32 AM <-> 10/13/2026, 10:32:52 AM Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Going to start playback of current track at 0:19 (track position in stream: 21:02) Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] Starting mpv Oct 13 10:32:52 primo-plus volumio[1216]: /bin/sh: 1: mpv: not found Oct 13 10:32:52 primo-plus volumio[1216]: error: [rp2] [mpv] Failed to get mpv version: Command failed: mpv --version Oct 13 10:32:52 primo-plus volumio[1216]: /bin/sh: 1: mpv: not found Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] [mpv] mpv process spawned Oct 13 10:32:52 primo-plus volumio[1216]: verbose: [rp2] Waiting for player event "playing"... Oct 13 10:32:52 primo-plus volumio[1216]: info: [rp2] [mpv] (PID: 26523) /bin/sh: 1: mpv: not found Oct 13 10:32:52 primo-plus volumio[1216]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 10:32:52 primo-plus volumio[1216]: TypeError: Cannot read properties of null (reading 'reset') Oct 13 10:32:52 primo-plus volumio[1216]: at /data/plugins/music_service/rp2/node_modules/volumio-ext-players/dist/mpv/MPVService.js:207:48 Oct 13 10:32:52 primo-plus volumio[1216]: at ChildProcess. (/data/plugins/music_service/rp2/node_modules/volumio-ext-players/dist/mpv/MPVService.js:221:19) Oct 13 10:32:52 primo-plus volumio[1216]: at ChildProcess.emit (node:events:514:28) Oct 13 10:32:52 primo-plus volumio[1216]: at maybeClose (node:internal/child_process:1105:16) Oct 13 10:32:52 primo-plus volumio[1216]: at Socket. (node:internal/child_process:457:11) Oct 13 10:32:52 primo-plus volumio[1216]: at Socket.emit (node:events:514:28) Oct 13 10:32:52 primo-plus volumio[1216]: at Pipe. (node:net:337:12) Oct 13 10:32:52 primo-plus volumio[1216]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 10:32:52 primo-plus sudo[26538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-13 10:31' Oct 13 10:32:52 primo-plus sudo[26538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="primoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Sep 16 19:52:30 UTC 2026" VOLUMIO_VERSION="4.209" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Primo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo Plus" VOLUMIO_HASH="d46f63e82ba06201f2d2d4410ea8070d"