Oct 02 10:39:00 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:01 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:01 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:01 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:07 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:09 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::Close All Modals sent Oct 02 10:39:12 primo-plus volumio[1181]: info: Starting Uninstall of plugin music_service - radio_paradise Oct 02 10:39:12 primo-plus volumio[1181]: info: Uninstalling plugin radio_paradise Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesRadio Paradise Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 10:39:12 primo-plus volumio[1181]: Cannot find translation for source QOBUZ Oct 02 10:39:12 primo-plus volumio[1181]: Cannot find translation for source Loopback Oct 02 10:39:12 primo-plus volumio[1181]: Cannot find translation for source TIDAL Oct 02 10:39:12 primo-plus volumio[1181]: Cannot find translation for source Spotify Oct 02 10:39:12 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:12.287+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:12 primo-plus volumio[1181]: info: Disabling plugin radio_paradise Oct 02 10:39:12 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:12.294+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:12 primo-plus volumio[1181]: info: Checking if uninstall.sh is present Oct 02 10:39:12 primo-plus volumio[1181]: info: Executing uninstall.sh Oct 02 10:39:12 primo-plus sudo[6291]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/radio_paradise/uninstall.sh Oct 02 10:39:12 primo-plus sudo[6291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:12 primo-plus sudo[6291]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:12 primo-plus volumio[1181]: info: Uninstall script completed Oct 02 10:39:12 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:12.381+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:12 primo-plus volumio[1181]: info: Removing plugin radio_paradise from configuration Oct 02 10:39:12 primo-plus volumio[1181]: info: Successfully removed radio_paradise configuration files Oct 02 10:39:12 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:12.423+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:12 primo-plus volumio[1181]: info: Plugin folders cleanup Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning into folder /volumio/app/plugins/ Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category audio_interface Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category miscellanea Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category music_service Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category plugins.json Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category system_controller Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category user_interface Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning into folder /data/plugins/ Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category audio_interface Oct 02 10:39:12 primo-plus volumio[1181]: info: Scanning category music_service Oct 02 10:39:12 primo-plus volumio[1181]: info: Cleaning folder for radio_paradise Oct 02 10:39:12 primo-plus volumio[1181]: info: Plugin folders cleanup completed Oct 02 10:39:12 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:12.533+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:12 primo-plus volumio[1181]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"3.0.5","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"FM/DAB Radio","name":"rtlsdr_radio","category":"music_service","version":"1.3.9","icon":"fa-signal","isManuallyInstalled":false,"enabled":false,"active":false},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.5.0","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true}] Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:12 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:13 primo-plus volumio[1181]: info: CoreCommandRouter::Close All Modals sent Oct 02 10:39:19 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:21 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:25 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:29 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:31 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:35 primo-plus volumio[1181]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/rp2/primoplus/bookworm/armhf Oct 02 10:39:35 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:35.435+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:35 primo-plus volumio[1181]: info: CoreCommandRouter::Close All Modals sent Oct 02 10:39:37 primo-plus volumio[1181]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/rp2/primoplus/bookworm/armhf Oct 02 10:39:37 primo-plus volumio[1181]: info: Folder /tmp/plugins removed Oct 02 10:39:37 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:37.257+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:37 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:37.996+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:37 primo-plus volumio[1181]: info: Check plugin dependencies Oct 02 10:39:38 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 10:39:38 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:38.064+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:38 primo-plus volumio[1181]: info: Checking if plugin already exists Oct 02 10:39:38 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:38.068+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:38 primo-plus volumio[1181]: info: Rename folder Oct 02 10:39:38 primo-plus volumio[1181]: info: Folder /tmp/downloaded_plugin.zip removed Oct 02 10:39:38 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:38.089+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:38 primo-plus volumio[1181]: info: Move to category Oct 02 10:39:38 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:38.931+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:38 primo-plus volumio[1181]: info: Checking if install.sh is present Oct 02 10:39:38 primo-plus volumio[1181]: info: Executing install.sh Oct 02 10:39:38 primo-plus sudo[6351]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/rp2/install.sh Oct 02 10:39:38 primo-plus sudo[6351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:38 primo-plus volumio[1181]: info: Installing mpv media player... Oct 02 10:39:38 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:38.998+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:39 primo-plus sudo[6353]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt update Oct 02 10:39:39 primo-plus sudo[6353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 02 10:39:39 primo-plus volumio[1181]: info: Get:1 http://archive.raspberrypi.com/debian bookworm InRelease [54.9 kB] Oct 02 10:39:39 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:39.136+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:39 primo-plus volumio[1181]: info: Hit:2 http://archive.raspbian.org/raspbian bookworm InRelease Oct 02 10:39:39 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:39.185+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:39 primo-plus volumio[1181]: info: Get:3 http://archive.raspberrypi.com/debian bookworm/main armhf Packages [587 kB] Oct 02 10:39:39 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:39.447+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:39 primo-plus volumio[1181]: info: Fetched 642 kB in 1s (819 kB/s) Oct 02 10:39:39 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:39.871+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:43 primo-plus volumio[1181]: info: Reading package lists... Oct 02 10:39:43 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:43.632+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:44 primo-plus volumio[1181]: info: Building dependency tree... Oct 02 10:39:44 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:44.206+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:44 primo-plus volumio[1181]: info: Reading state information... Oct 02 10:39:44 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:44.218+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:44 primo-plus sudo[6353]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:44 primo-plus volumio[1181]: info: 57 packages can be upgraded. Run 'apt list --upgradable' to see them. Oct 02 10:39:44 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:44.286+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:44 primo-plus sudo[6521]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get install -y mpv Oct 02 10:39:44 primo-plus sudo[6521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 02 10:39:44 primo-plus volumio[1181]: info: Reading package lists... Oct 02 10:39:44 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:44.426+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:44 primo-plus volumio[1181]: info: Building dependency tree... Oct 02 10:39:44 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:44.969+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:44 primo-plus volumio[1181]: info: Reading state information... Oct 02 10:39:44 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:44.981+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: You might want to run 'apt --fix-broken install' to correct these. Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.010+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: The following packages have unmet dependencies: Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.013+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: libpython3.11 : Depends: libpython3.11-stdlib (= 3.11.2-6+deb12u8) but 3.11.2-6+deb12u7 is to be installed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.554+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: libpython3.11-stdlib : Depends: libpython3.11-minimal (= 3.11.2-6+deb12u7) but 3.11.2-6+deb12u8 is to be installed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.558+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus sudo[6521]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:45 primo-plus volumio[1181]: info: mpv : Depends: libdvdnav4 (>= 4.1.3) but it is not going to be installed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.566+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: Depends: liblua5.2-0 (>= 5.2.4) but it is not going to be installed Oct 02 10:39:45 primo-plus volumio[1181]: info: Depends: libmujs2 (>= 1.0.7) but it is not going to be installed Oct 02 10:39:45 primo-plus volumio[1181]: info: Depends: libsixel1 (>= 1.10.3) but it is not going to be installed Oct 02 10:39:45 primo-plus volumio[1181]: info: Depends: libuchardet0 (>= 0.0.1) but it is not going to be installed Oct 02 10:39:45 primo-plus sudo[6351]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:45 primo-plus volumio[1181]: info: Depends: libva-wayland2 (>= 1.3.0) but it is not going to be installed Oct 02 10:39:45 primo-plus volumio[1181]: info: Depends: libxpresent1 but it is not going to be installed Oct 02 10:39:45 primo-plus volumio[1181]: info: Recommends: yt-dlp but it is not going to be installed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.571+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.572+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.572+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.573+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.573+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.573+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.574+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: Install script completed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.594+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: Adding reference to registry Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.599+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: Done installing plugin. Oct 02 10:39:45 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:45 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:45 primo-plus volumio[1181]: info: python3.11 : Depends: libpython3.11-stdlib (= 3.11.2-6+deb12u8) but 3.11.2-6+deb12u7 is to be installed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.613+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: info: Folder /tmp/plugins removed Oct 02 10:39:45 primo-plus volumio[1181]: info: Folder /tmp/downloaded_plugin.zip removed Oct 02 10:39:45 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:45 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:45 primo-plus volumio[1181]: info: Folder /data/temp removed Oct 02 10:39:45 primo-plus volumio[1181]: info: RP2 plugin installed Oct 02 10:39:45 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:45.651+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 02 10:39:45 primo-plus volumio[1181]: Plugin install end detected on script Oct 02 10:39:47 primo-plus volumio[1181]: info: Enabling plugin rp2 Oct 02 10:39:47 primo-plus volumio[1181]: info: Loading plugin "rp2"... Oct 02 10:39:49 primo-plus volumio[1181]: info: PLUGIN START: rp2 Oct 02 10:39:49 primo-plus volumio[1181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 02 10:39:49 primo-plus volumio[1181]: info: [1790933989020] CoreMusicLibrary::Adding element Radio Paradise (RP2) Oct 02 10:39:49 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 10:39:49 primo-plus volumio[1181]: Cannot find translation for source QOBUZ Oct 02 10:39:49 primo-plus volumio[1181]: Cannot find translation for source Loopback Oct 02 10:39:49 primo-plus volumio[1181]: Cannot find translation for source TIDAL Oct 02 10:39:49 primo-plus volumio[1181]: Cannot find translation for source Spotify Oct 02 10:39:49 primo-plus volumio[1181]: Cannot find translation for source Radio Paradise (RP2) Oct 02 10:39:49 primo-plus volumio[1181]: info: Done. Oct 02 10:39:49 primo-plus volumio[1181]: info: CoreCommandRouter::Close All Modals sent Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.202+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.4.33:63514 @ 0x24b4060" latency=6.736401ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.216+01:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.221+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=4.610751ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.238+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=21.403137ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.242+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=http://pushupdates.volumio.org duration=23.536803ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.248+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=29.663915ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.257+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://google.com duration=40.382577ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.321+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=103.251438ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.323+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://www.googleapis.com duration=105.783207ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.335+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://database.volumio.cloud duration=116.40174ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.340+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://functions.volumio.cloud duration=121.627424ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.342+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://securetoken.googleapis.com duration=124.474744ms Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.344+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=https://functions.volumio.cloud duration=125.924496ms Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 10:39:51 primo-plus volumio[1181]: info: Discovery: Getting this device information Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 10:39:51 primo-plus volumio[1181]: verbose: New Socket.io Connection to 192.168.4.131 from 192.168.4.33 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.260911.1 Engine version: 3 Transport: websocket Total Clients: 11 Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetQueue Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreStateMachine::getQueue Oct 02 10:39:51 primo-plus volumio[1181]: info: CorePlayQueue::getQueue Oct 02 10:39:51 primo-plus volumio[1181]: info: Received Get System Version Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 10:39:51 primo-plus volumio[1181]: info: Received Get System Info Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 10:39:51 primo-plus volumio[1181]: info: Discovery: Getting this device information Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getUpdaterChannel Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 02 10:39:51 primo-plus volumio[1181]: info: CALLMETHOD: miscellanea novaui getTheme [object Object] Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: novaui , getTheme Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 02 10:39:51 primo-plus sudo[6542]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 02 10:39:51 primo-plus sudo[6542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:51 primo-plus sudo[6542]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:51 primo-plus sudo[6547]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 02 10:39:51 primo-plus sudo[6547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:51 primo-plus sudo[6547]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:51 primo-plus sudo[6554]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 02 10:39:51 primo-plus sudo[6560]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 02 10:39:51 primo-plus sudo[6554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:51 primo-plus sudo[6560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:51 primo-plus sudo[6560]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 02 10:39:51 primo-plus sudo[6554]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 10:39:51 primo-plus sudo[6566]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 02 10:39:51 primo-plus sudo[6566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:51 primo-plus volumio[1181]: info: Received Get System Version Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 10:39:51 primo-plus volumio[1181]: info: Received Get System Info Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 10:39:51 primo-plus sudo[6566]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:51 primo-plus volumio[1181]: info: Discovery: Getting this device information Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetQueue Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreStateMachine::getQueue Oct 02 10:39:51 primo-plus volumio[1181]: info: CorePlayQueue::getQueue Oct 02 10:39:51 primo-plus sudo[6570]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 02 10:39:51 primo-plus sudo[6570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 02 10:39:51 primo-plus sudo[6570]: pam_unix(sudo:session): session closed for user root Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 10:39:51 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.760+01:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=http://cddb.volumio.org duration=543.216169ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 02 10:39:51 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:39:51.815+01:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.4.33:63514 @ 0x24b4060" latency=6.602859ms timeout=10s endpoint=http://plugins.volumio.org duration=596.341592ms Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:52 primo-plus volumio[1181]: info: Received Get System Version Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 10:39:52 primo-plus volumio[1181]: info: Received Get System Info Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 10:39:52 primo-plus volumio[1181]: info: Discovery: Getting this device information Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 02 10:39:52 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 10:39:54 primo-plus volumio[1181]: info: Retrieving Cloud Streaming UI Oct 02 10:39:54 primo-plus volumio[1181]: info: Getting Tidal Cloud Configuration Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 10:39:54 primo-plus volumio[1181]: info: Getting Qobuz Cloud Configuration Oct 02 10:39:54 primo-plus volumio[1181]: info: Asking plugin for UI Config Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 10:39:54 primo-plus volumio[1181]: info: Getting Spotify Cloud Configuration Oct 02 10:39:54 primo-plus volumio[1181]: info: Asking plugin for UI Config Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 10:39:54 primo-plus volumio[1181]: info: Saving Spotify Acccount Oct 02 10:39:54 primo-plus volumio[1181]: info: Got it Oct 02 10:39:54 primo-plus volumio[1181]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 02 10:39:54 primo-plus volumio[1181]: info: Got Tidal Cloud Configuration Oct 02 10:39:54 primo-plus volumio[1181]: info: Got it Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 02 10:39:54 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: networkfs , listUsbDrives Oct 02 10:39:54 primo-plus volumio[1181]: info: Error : CoreCommandRouter::executeOnPlugin: No method [listUsbDrives] in plugin networkfs Oct 02 10:39:54 primo-plus volumio[1181]: error: Error on listing USB devices Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 02 10:39:55 primo-plus volumio[1181]: info: Received Get System Version Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 10:39:55 primo-plus volumio[1181]: info: Received Get System Info Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 10:39:55 primo-plus volumio[1181]: info: Discovery: Getting this device information Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:39:55 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 10:39:57 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 10:39:57 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 10:40:00 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Oct 02 10:40:01 primo-plus volumio[1181]: info: Preload queue cleared Oct 02 10:40:02 primo-plus volumio[1181]: info: Preload queue cleared Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::ClearQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::stop Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::serviceStop Oct 02 10:40:02 primo-plus volumio[1181]: info: Received STOP, but no service to execute it Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::clearPlayQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::saveQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioPushQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::addQueueItems Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::addQueueItems Oct 02 10:40:02 primo-plus volumio[1181]: info: Preload queue cleared Oct 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioPushQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::saveQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::updateTrackBlock Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrackBlock Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioPlay Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::play index 0 Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::addQueueItems Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::addQueueItems Oct 02 10:40:02 primo-plus volumio[1181]: info: Preload queue cleared Oct 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: 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 02 10:40:02 primo-plus volumio[1181]: info: Adding Item to queue: rp2/episodes@channel=2050@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fepisodes%40channel%3D2050%22%2C%22name%22%3A%22Radio%202050%22%2C%22title%22%3A%22Radio%202050%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F2050%2Fcover_512x512%2F0.jpg%22%7D Oct 02 10:40:02 primo-plus volumio[1181]: info: Exploding uri rp2/episodes@channel=2050@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fepisodes%40channel%3D2050%22%2C%22name%22%3A%22Radio%202050%22%2C%22title%22%3A%22Radio%202050%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F2050%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::stop Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::updateTrackBlock Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrackBlock Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::stPlaybackTimer Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::pushState Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrack 2 Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioPushState Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioGetState Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrack 2 Oct 02 10:40:02 primo-plus volumio[1181]: info: MRS: Pushing multiroomSync output update for this device Oct 02 10:40:02 primo-plus volumio[1181]: info: MRS: Pushing multiroomSync output Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::serviceStop Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrack 2 Oct 02 10:40:02 primo-plus volumio[1181]: info: ControllerMpd::stop Oct 02 10:40:02 primo-plus volumio[1181]: verbose: ControllerMpd::sendMpdCommand stop Oct 02 10:40:02 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:40:02.921+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.4.33:63514 @ 0x24b4060" state=STATUS_STOPPED positionMs=0 volume=48 Oct 02 10:40:02 primo-plus volumio5-onboarding[1735]: time=2026-10-02T10:40:02.922+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.4.33:63514 @ 0x24b4060" id= title= Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::volumioPushQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::saveQueue Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::updateTrackBlock Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrackBlock Oct 02 10:40:02 primo-plus volumio[1181]: info: FusionDsp - Volumio is not playing Oct 02 10:40:02 primo-plus volumio[1181]: info: FusionDsp - Clipped samples monitor stopped Oct 02 10:40:02 primo-plus volumio[1181]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Oct 02 10:40:02 primo-plus volumio[1181]: info: Updating RAAT Signal Path Oct 02 10:40:02 primo-plus volumio[1181]: info: sendMpdCommand stop took 44 milliseconds Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::play index undefined Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrack 0 Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreStateMachine::startPlaybackTimer Oct 02 10:40:02 primo-plus volumio[1181]: info: CorePlayQueue::getTrack 0 Oct 02 10:40:02 primo-plus volumio[1181]: info: [rp2] clearAddPlayTrack: rp2/channel@id=0 Oct 02 10:40:02 primo-plus volumio[1181]: info: CoreCommandRouter::executeOnPlugin: last_100 , handleBrowseUri Oct 02 10:40:03 primo-plus volumio[1181]: 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 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Obtained block for channel "0" Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] ------------- Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Block summary Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] ------------- Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Stream URL: https://audio.radioparadise.stream/audio/blocks/0/x/2156/4/b/2156-0.flac Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Tracks: Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] 0. Long & Lost (3:04 | elapsed: 8m 40s) Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] 1. I Close My Eyes (4:04 | elapsed: 11m 45s) Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] 2. Bron-y-aur Stomp (4:12 | elapsed: 15m 49s) Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] 3. Wild Horses (3:46 | elapsed: 20m 1s) Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] 4. White Gloves ii (4:46 | elapsed: 23m 48s) Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Oct 02 10:40:03 primo-plus volumio[1181]: verbose: [rp2] Current track scheduled playback vs. current time: 10/2/2026, 10:37:36 AM <-> 10/2/2026, 10:40:03 AM Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Going to start playback of current track at 2:26 (track position in stream: 8:40) Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] Starting mpv Oct 02 10:40:03 primo-plus volumio[1181]: /bin/sh: 1: mpv: not found Oct 02 10:40:03 primo-plus volumio[1181]: error: [rp2] [mpv] Failed to get mpv version: Command failed: mpv --version Oct 02 10:40:03 primo-plus volumio[1181]: /bin/sh: 1: mpv: not found Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] [mpv] mpv process spawned Oct 02 10:40:03 primo-plus volumio[1181]: verbose: [rp2] Waiting for player event "playing"... Oct 02 10:40:03 primo-plus volumio[1181]: info: [rp2] [mpv] (PID: 6604) /bin/sh: 1: mpv: not found Oct 02 10:40:03 primo-plus volumio[1181]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 10:40:03 primo-plus volumio[1181]: TypeError: Cannot read properties of null (reading 'reset') Oct 02 10:40:03 primo-plus volumio[1181]: at /data/plugins/music_service/rp2/node_modules/volumio-ext-players/dist/mpv/MPVService.js:207:48 Oct 02 10:40:03 primo-plus volumio[1181]: at ChildProcess. (/data/plugins/music_service/rp2/node_modules/volumio-ext-players/dist/mpv/MPVService.js:221:19) Oct 02 10:40:03 primo-plus volumio[1181]: at ChildProcess.emit (node:events:514:28) Oct 02 10:40:03 primo-plus volumio[1181]: at maybeClose (node:internal/child_process:1105:16) Oct 02 10:40:03 primo-plus volumio[1181]: at Socket. (node:internal/child_process:457:11) Oct 02 10:40:03 primo-plus volumio[1181]: at Socket.emit (node:events:514:28) Oct 02 10:40:03 primo-plus volumio[1181]: at Pipe. (node:net:337:12) Oct 02 10:40:03 primo-plus volumio[1181]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 10:40:04 primo-plus sudo[6619]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-02 10:39' Oct 02 10:40:04 primo-plus sudo[6619]: 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"