-- Logs begin at Sat 2026-01-10 14:47:41 CET, end at Sat 2026-01-10 14:52:42 CET. -- Jan 10 14:52:21 rivoplus volumio5-onboarding[3894]: time=2026-01-10T14:52:21.403+01:00 level=INFO msg="enable music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.178.110:51268,00:00:00:00:00:00%01,192.168.178.110:51271 @ 0x2c2d4d0" latency=55.262411ms timeout=10s provider=spotify Jan 10 14:52:21 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:21 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:21 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:22 rivoplus volumio[3408]: info: Received Get System Info Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 14:52:22 rivoplus volumio[3408]: info: Discovery: Getting this device information Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::volumioGetState Jan 10 14:52:22 rivoplus volumio[3408]: info: CorePlayQueue::getTrack 0 Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 14:52:22 rivoplus volumio5-onboarding[3894]: time=2026-01-10T14:52:22.264+01:00 level=INFO msg="installing required plugin for music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.178.110:51268,00:00:00:00:00:00%01,192.168.178.110:51271 @ 0x2c2d4d0" latency=55.262411ms timeout=10s provider=spotify plugin=spop Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:22 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:23 rivoplus volumio[3408]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/rivoplus/buster/armhf Jan 10 14:52:24 rivoplus volumio[3408]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/rivoplus/buster/armhf Jan 10 14:52:24 rivoplus volumio[3408]: info: Folder /tmp/plugins removed Jan 10 14:52:24 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:25 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:25 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:25 rivoplus volumio[3408]: info: Check plugin dependencies Jan 10 14:52:26 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 10 14:52:26 rivoplus volumio[3408]: info: Checking if plugin already exists Jan 10 14:52:26 rivoplus volumio[3408]: info: Rename folder Jan 10 14:52:26 rivoplus volumio[3408]: info: Folder /tmp/downloaded_plugin.zip removed Jan 10 14:52:26 rivoplus volumio[3408]: info: Move to category Jan 10 14:52:26 rivoplus volumio[3408]: info: Checking if install.sh is present Jan 10 14:52:26 rivoplus volumio[3408]: info: Executing install.sh Jan 10 14:52:26 rivoplus sudo[5180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh Jan 10 14:52:26 rivoplus sudo[5180]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 10 14:52:26 rivoplus volumio[3408]: info: Installing Go-librespot Jan 10 14:52:26 rivoplus volumio[3408]: info: Checking old vollibrespot installs Jan 10 14:52:26 rivoplus systemd[1]: Reloading. Jan 10 14:52:27 rivoplus systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jan 10 14:52:27 rivoplus systemd[1]: serial-getty@ttyS0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jan 10 14:52:27 rivoplus volumio[3408]: info: Downloading daemon Jan 10 14:52:29 rivoplus volumio[3408]: info: Creating directories Jan 10 14:52:29 rivoplus volumio[3408]: info: Creating data directory Jan 10 14:52:29 rivoplus volumio[3408]: info: Creating Start Script Jan 10 14:52:29 rivoplus systemd[1]: Reloading. Jan 10 14:52:30 rivoplus systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jan 10 14:52:30 rivoplus sudo[5180]: pam_unix(sudo:session): session closed for user root Jan 10 14:52:30 rivoplus volumio[3408]: info: Install script completed Jan 10 14:52:30 rivoplus volumio[3408]: info: Adding reference to registry Jan 10 14:52:30 rivoplus volumio[3408]: info: Done installing plugin. Jan 10 14:52:30 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:30 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:30 rivoplus volumio[3408]: Plugin install end detected on script Jan 10 14:52:30 rivoplus volumio[3408]: info: Folder /tmp/plugins removed Jan 10 14:52:30 rivoplus volumio[3408]: info: Folder /tmp/downloaded_plugin.zip removed Jan 10 14:52:30 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:30 rivoplus volumio[3408]: info: Folder /data/temp removed Jan 10 14:52:30 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:30 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:31 rivoplus volumio[3408]: info: Enabling plugin spop Jan 10 14:52:31 rivoplus volumio[3408]: info: Loading plugin "spop"... Jan 10 14:52:32 rivoplus volumio[3408]: info: PLUGIN START: spop Jan 10 14:52:32 rivoplus volumio[3408]: info: Creating Spotify config file Jan 10 14:52:32 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 14:52:32 rivoplus volumio[3408]: info: Done. Jan 10 14:52:32 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:33 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:33 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:33 rivoplus volumio[3408]: info: Spotify config file written Jan 10 14:52:33 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:33 rivoplus volumio[3408]: info: No need to fix Spotify hosts Jan 10 14:52:33 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:33 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:33 rivoplus sudo[5253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 10 14:52:33 rivoplus sudo[5253]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 10 14:52:33 rivoplus systemd[1]: Started go-librespot Daemon. Jan 10 14:52:33 rivoplus go-librespot[5255]: go-librespot daemon starting... Jan 10 14:52:33 rivoplus sudo[5253]: pam_unix(sudo:session): session closed for user root Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=info msg="running go-librespot 0.6.2" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=debug msg="no app state found" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=debug msg="stored credentials not found" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=info msg="generated new device id: 29098f14e065153976ea3e5ca1e2c50b8b5d29e3" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 10 14:52:33 rivoplus go-librespot[5255]: time="2026-01-10T14:52:33+01:00" level=info msg="zeroconf server listening on port 37517" Jan 10 14:52:36 rivoplus volumio[3408]: info: go-librespot daemon successfully initialized Jan 10 14:52:38 rivoplus volumio5-onboarding[3894]: time=2026-01-10T14:52:38.948+01:00 level=INFO msg="enable music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.178.110:51268,00:00:00:00:00:00%01,192.168.178.110:51271 @ 0x2c2d4d0" latency=19.688753ms timeout=10s provider=soundcloud Jan 10 14:52:38 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:38 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:38 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:39 rivoplus volumio[3408]: info: Initializing connection to go-librespot Websocket Jan 10 14:52:39 rivoplus go-librespot[5255]: time="2026-01-10T14:52:39+01:00" level=debug msg="new websocket client" Jan 10 14:52:39 rivoplus volumio[3408]: info: Connection to go-librespot Websocket established Jan 10 14:52:39 rivoplus volumio[3408]: info: Received Get System Info Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 14:52:39 rivoplus volumio[3408]: info: Discovery: Getting this device information Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::volumioGetState Jan 10 14:52:39 rivoplus volumio[3408]: info: CorePlayQueue::getTrack 0 Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 14:52:39 rivoplus volumio5-onboarding[3894]: time=2026-01-10T14:52:39.667+01:00 level=INFO msg="installing required plugin for music provider" component=server type=REQUEST_TYPE_ENABLE_MUSIC_PROVIDER peer="192.168.178.110:51268,00:00:00:00:00:00%01,192.168.178.110:51271 @ 0x2c2d4d0" latency=19.688753ms timeout=10s provider=soundcloud plugin=soundcloud Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:39 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:40 rivoplus volumio[3408]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/rivoplus/buster/armhf Jan 10 14:52:41 rivoplus volumio[3408]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/rivoplus/buster/armhf Jan 10 14:52:41 rivoplus volumio[3408]: info: Folder /tmp/plugins removed Jan 10 14:52:41 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:41 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:41 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 10 14:52:42 rivoplus volumio[3408]: info: Check plugin dependencies Jan 10 14:52:42 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 10 14:52:42 rivoplus volumio[3408]: info: Checking if plugin already exists Jan 10 14:52:42 rivoplus volumio[3408]: info: Rename folder Jan 10 14:52:42 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:42 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:42 rivoplus volumio[3408]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 14:52:42 rivoplus volumio[3408]: info: Folder /tmp/downloaded_plugin.zip removed Jan 10 14:52:42 rivoplus volumio[3408]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 14:52:42 rivoplus volumio[3408]: TypeError: Cannot read property 'plugin_type' of undefined Jan 10 14:52:42 rivoplus volumio[3408]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1644:56) Jan 10 14:52:42 rivoplus volumio[3408]: at PluginManager.getAvailablePlugins (/volumio/app/pluginmanager.js:1691:24) Jan 10 14:52:42 rivoplus volumio[3408]: at CoreCommandRouter.getAvailablePlugins (/volumio/app/index.js:1544:29) Jan 10 14:52:42 rivoplus volumio[3408]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1365:45) Jan 10 14:52:42 rivoplus volumio[3408]: at Socket.emit (events.js:400:28) Jan 10 14:52:42 rivoplus volumio[3408]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jan 10 14:52:42 rivoplus volumio[3408]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jan 10 14:52:42 rivoplus volumio[3408]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 14:52:42 rivoplus sudo[5301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-10 14:51 Jan 10 14:52:42 rivoplus sudo[5301]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:47:33 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="9e8aa5d6afb5e5d87a87bafae7aa5647"