Apr 14 02:42:11 volumio volumio[1039]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/now_playing/volumio/bookworm/amd64 Apr 14 02:42:11 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:11.221Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio[1039]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/now_playing/volumio/bookworm/amd64 Apr 14 02:42:14 volumio volumio[1039]: info: Folder /tmp/plugins removed Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.165Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.452Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio[1039]: info: Check plugin dependencies Apr 14 02:42:14 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.471Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio[1039]: info: Checking if plugin already exists Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.473Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio[1039]: info: Rename folder Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.480Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio[1039]: info: Move to category Apr 14 02:42:14 volumio volumio[1039]: info: Folder /tmp/downloaded_plugin.zip removed Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.617Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio volumio[1039]: info: Checking if install.sh is present Apr 14 02:42:14 volumio volumio[1039]: info: Executing install.sh Apr 14 02:42:14 volumio sudo[11978]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/now_playing/install.sh Apr 14 02:42:14 volumio sudo[11978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:42:14 volumio volumio[1039]: info: Installing geo-tz node dependency Apr 14 02:42:14 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:14.639Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:14 volumio su[11982]: (to volumio) root on none Apr 14 02:42:14 volumio su[11982]: pam_unix(su:session): session opened for user volumio(uid=1000) by (uid=0) Apr 14 02:42:14 volumio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Apr 14 02:42:14 volumio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Apr 14 02:42:14 volumio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Apr 14 02:42:14 volumio systemd[1]: Starting user@1000.service - User Manager for UID 1000... Apr 14 02:42:14 volumio (systemd)[11984]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Apr 14 02:42:14 volumio systemd[11984]: Queued start job for default target default.target. Apr 14 02:42:14 volumio systemd[11984]: Created slice app.slice - User Application Slice. Apr 14 02:42:14 volumio systemd[11984]: Reached target paths.target - Paths. Apr 14 02:42:14 volumio systemd[11984]: Reached target timers.target - Timers. Apr 14 02:42:14 volumio systemd[11984]: Starting dbus.socket - D-Bus User Message Bus Socket... Apr 14 02:42:14 volumio systemd[11984]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Apr 14 02:42:14 volumio systemd[11984]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 14 02:42:14 volumio systemd[11984]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 14 02:42:14 volumio systemd[11984]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 14 02:42:14 volumio systemd[11984]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 14 02:42:14 volumio systemd[11984]: Listening on dbus.socket - D-Bus User Message Bus Socket. Apr 14 02:42:14 volumio systemd[11984]: Reached target sockets.target - Sockets. Apr 14 02:42:14 volumio systemd[11984]: Reached target basic.target - Basic System. Apr 14 02:42:14 volumio systemd[1]: Started user@1000.service - User Manager for UID 1000. Apr 14 02:42:14 volumio systemd[11984]: Started mpris-proxy.service - Bluetooth mpris proxy. Apr 14 02:42:14 volumio systemd[11984]: Reached target default.target - Main User Target. Apr 14 02:42:14 volumio systemd[11984]: Startup finished in 110ms. Apr 14 02:42:14 volumio systemd[1]: Started session-c1.scope - Session c1 of User volumio. Apr 14 02:42:14 volumio systemd[11984]: Created slice session.slice - User Core Session Slice. Apr 14 02:42:14 volumio systemd[11984]: Starting dbus.service - D-Bus User Message Bus... Apr 14 02:42:14 volumio systemd[11984]: Started dbus.service - D-Bus User Message Bus. Apr 14 02:42:27 volumio go-librespot[1923]: time="2026-04-14T02:42:27Z" level=trace msg="sent dealer ping" Apr 14 02:42:27 volumio go-librespot[1923]: time="2026-04-14T02:42:27Z" level=trace msg="received dealer pong" Apr 14 02:42:28 volumio volumio[1039]: info: Apr 14 02:42:28 volumio volumio[1039]: info: added 27 packages, changed 4 packages, and audited 162 packages in 13s Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.178Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.178Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.180Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: 24 packages are looking for funding Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.183Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: run `npm fund` for details Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.186Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.189Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio su[11982]: pam_unix(su:session): session closed for user volumio Apr 14 02:42:28 volumio volumio[1039]: info: 6 vulnerabilities (1 low, 1 moderate, 4 high) Apr 14 02:42:28 volumio volumio[1039]: info: Apr 14 02:42:28 volumio volumio[1039]: info: To address all issues, run: Apr 14 02:42:28 volumio volumio[1039]: info: npm audit fix Apr 14 02:42:28 volumio volumio[1039]: info: Apr 14 02:42:28 volumio volumio[1039]: info: Run `npm audit` for details. Apr 14 02:42:28 volumio systemd[1]: session-c1.scope: Deactivated successfully. Apr 14 02:42:28 volumio systemd[1]: session-c1.scope: Consumed 15.601s CPU time. Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.194Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.195Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.195Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.196Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.196Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.196Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio sudo[11978]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:28 volumio volumio[1039]: info: Install script completed Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.205Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: Adding reference to registry Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.207Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: Done installing plugin. Apr 14 02:42:28 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 02:42:28 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 14 02:42:28 volumio volumio[1039]: info: Folder /tmp/plugins removed Apr 14 02:42:28 volumio volumio[1039]: info: Folder /tmp/downloaded_plugin.zip removed Apr 14 02:42:28 volumio volumio[1039]: info: Folder /data/temp removed Apr 14 02:42:28 volumio volumio[1039]: info: Creating user directories (if not exist) Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.217Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:28 volumio volumio[1039]: info: Now Playing plugin installed Apr 14 02:42:28 volumio volumio[1039]: Plugin install end detected on script Apr 14 02:42:28 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:28.219Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:30 volumio volumio[1039]: info: Enabling plugin now_playing Apr 14 02:42:30 volumio volumio[1039]: info: Loading plugin "now_playing"... Apr 14 02:42:30 volumio volumio[1039]: info: PLUGIN START: now_playing Apr 14 02:42:30 volumio volumio[1039]: info: [now-playing] ConfigUpdater: config version unavailable. Either this is the first time the plugin is installed, or the previous version is < 0.3.0). Config will not be updated. Apr 14 02:42:30 volumio volumio[1039]: info: [now-playing] ConfigUpdater: updated config version to 1.0.6 Apr 14 02:42:30 volumio volumio[1039]: info: [now-playing] App is listening on port 4004. Apr 14 02:42:30 volumio volumio[1039]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Apr 14 02:42:30 volumio volumio[1039]: info: Done. Apr 14 02:42:38 volumio systemd[1]: Stopping user@1000.service - User Manager for UID 1000... Apr 14 02:42:38 volumio systemd[11984]: Activating special unit exit.target... Apr 14 02:42:38 volumio systemd[11984]: Stopped target default.target - Main User Target. Apr 14 02:42:38 volumio systemd[11984]: Stopping mpris-proxy.service - Bluetooth mpris proxy... Apr 14 02:42:38 volumio mpris-proxy[12000]: org.bluez appeared Apr 14 02:42:38 volumio mpris-proxy[12000]: org.bluez disappeared Apr 14 02:42:38 volumio systemd[11984]: Stopped mpris-proxy.service - Bluetooth mpris proxy. Apr 14 02:42:38 volumio systemd[11984]: Stopping dbus.service - D-Bus User Message Bus... Apr 14 02:42:38 volumio systemd[11984]: Stopped dbus.service - D-Bus User Message Bus. Apr 14 02:42:38 volumio systemd[11984]: Removed slice session.slice - User Core Session Slice. Apr 14 02:42:38 volumio systemd[11984]: Stopped target basic.target - Basic System. Apr 14 02:42:38 volumio systemd[11984]: Stopped target paths.target - Paths. Apr 14 02:42:38 volumio systemd[11984]: Stopped target sockets.target - Sockets. Apr 14 02:42:38 volumio systemd[11984]: Stopped target timers.target - Timers. Apr 14 02:42:38 volumio systemd[11984]: Closed dbus.socket - D-Bus User Message Bus Socket. Apr 14 02:42:38 volumio systemd[11984]: Closed dirmngr.socket - GnuPG network certificate management daemon. Apr 14 02:42:38 volumio systemd[11984]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 14 02:42:38 volumio systemd[11984]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 14 02:42:38 volumio systemd[11984]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 14 02:42:38 volumio systemd[11984]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 14 02:42:38 volumio systemd[11984]: Removed slice app.slice - User Application Slice. Apr 14 02:42:38 volumio systemd[11984]: Reached target shutdown.target - Shutdown. Apr 14 02:42:38 volumio systemd[11984]: Finished systemd-exit.service - Exit the Session. Apr 14 02:42:38 volumio systemd[11984]: Reached target exit.target - Exit the Session. Apr 14 02:42:38 volumio systemd[1]: user@1000.service: Deactivated successfully. Apr 14 02:42:38 volumio systemd[1]: Stopped user@1000.service - User Manager for UID 1000. Apr 14 02:42:38 volumio systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Apr 14 02:42:38 volumio systemd[1]: run-user-1000.mount: Deactivated successfully. Apr 14 02:42:38 volumio systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. Apr 14 02:42:38 volumio systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Apr 14 02:42:38 volumio systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. Apr 14 02:42:38 volumio systemd[1]: user-1000.slice: Consumed 15.730s CPU time. Apr 14 02:42:42 volumio volumio[1039]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/peppymeterbasic/volumio/bookworm/amd64 Apr 14 02:42:42 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:42.093Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio[1039]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/peppymeterbasic/volumio/bookworm/amd64 Apr 14 02:42:44 volumio volumio[1039]: info: Folder /tmp/plugins removed Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.267Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.321Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio[1039]: info: Check plugin dependencies Apr 14 02:42:44 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.330Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio[1039]: info: Checking if plugin already exists Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.332Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio[1039]: info: Rename folder Apr 14 02:42:44 volumio volumio[1039]: info: Folder /tmp/downloaded_plugin.zip removed Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.339Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio[1039]: info: Move to category Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.630Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio volumio[1039]: info: Checking if install.sh is present Apr 14 02:42:44 volumio volumio[1039]: info: Executing install.sh Apr 14 02:42:44 volumio sudo[12135]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/peppymeterbasic/install.sh Apr 14 02:42:44 volumio sudo[12135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:42:44 volumio volumio[1039]: info: Installing peppyalsa plugin dependencies Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.652Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:44 volumio sudo[12139]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get update Apr 14 02:42:44 volumio sudo[12139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:42:44 volumio volumio[1039]: info: Hit:1 http://deb.debian.org/debian bookworm InRelease Apr 14 02:42:44 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:44.763Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:46 volumio volumio[1039]: info: Reading package lists... Apr 14 02:42:46 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:46.011Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:46 volumio sudo[12139]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:46 volumio volumio[1039]: info: cloning peppymeter repo Apr 14 02:42:46 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:46.027Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio go-librespot[1923]: time="2026-04-14T02:42:57Z" level=trace msg="received accesspoint ping" Apr 14 02:42:57 volumio go-librespot[1923]: time="2026-04-14T02:42:57Z" level=trace msg="received accesspoint pong ack" Apr 14 02:42:57 volumio go-librespot[1923]: time="2026-04-14T02:42:57Z" level=trace msg="sent dealer ping" Apr 14 02:42:57 volumio go-librespot[1923]: time="2026-04-14T02:42:57Z" level=trace msg="received dealer pong" Apr 14 02:42:57 volumio sudo[12282]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chown -R volumio /data/plugins/user_interface/peppymeterbasic /data/INTERNAL/PeppyMeterBasic/Templates Apr 14 02:42:57 volumio sudo[12282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:42:57 volumio sudo[12282]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:57 volumio sudo[12284]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chgrp -R volumio /data/plugins/user_interface/peppymeterbasic /data/INTERNAL/PeppyMeterBasic/Templates Apr 14 02:42:57 volumio sudo[12284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:42:57 volumio sudo[12284]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:57 volumio volumio[1039]: info: installing apt packages Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.440Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio sudo[12286]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/apt-get -yf install python3-pygame python3-pip python3-dev libjpeg-dev zlib1g-dev libfftw3-dev Apr 14 02:42:57 volumio sudo[12286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:42:57 volumio volumio[1039]: info: Reading package lists... Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.473Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: Building dependency tree... Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.708Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: Reading state information... Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.713Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: python3-pip is already the newest version (23.0.1+dfsg-1). Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.723Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: You might want to run 'apt --fix-broken install' to correct these. Apr 14 02:42:57 volumio volumio[1039]: info: The following packages have unmet dependencies: Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.726Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.726Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: jellyfin-ffmpeg6 : Depends: libllvm16 but it is not going to be installed Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.842Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: libfftw3-dev : Depends: libfftw3-bin (= 3.3.10-1) Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.845Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libfftw3-double3 (= 3.3.10-1) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libfftw3-long3 (= 3.3.10-1) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libfftw3-quad3 (= 3.3.10-1) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: libjpeg-dev : Depends: libjpeg62-turbo-dev (>= 1:2.1.5-2) but it is not going to be installed Apr 14 02:42:57 volumio sudo[12286]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.850Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.850Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.850Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.850Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio sudo[12293]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl daemon-reload Apr 14 02:42:57 volumio sudo[12293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:42:57 volumio volumio[1039]: info: python3-dev : Depends: libpython3-dev (= 3.11.2-1+b1) but it is not going to be installed Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.857Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: Depends: python3.11-dev (>= 3.11.2-1~) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: python3-pygame : Depends: fonts-freefont-ttf but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: python3-numpy (>= 1:1.22.0) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: python3-numpy-abi9 Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libportmidi0 but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libsdl2-image-2.0-0 (>= 2.0.5) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libsdl2-mixer-2.0-0 (>= 2.0.4) but it is not going to be installed Apr 14 02:42:57 volumio volumio[1039]: info: Depends: libsdl2-ttf-2.0-0 (>= 2.0.15) but it is not going to be installed Apr 14 02:42:57 volumio systemd[1]: Reloading. Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.865Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: zlib1g-dev : Depends: libc6-dev but it is not going to be installed or Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.876Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:57 volumio volumio[1039]: info: libc-dev Apr 14 02:42:57 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:57.877Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:58 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 02:42:58 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 02:42:58 volumio systemd[1]: /lib/systemd/system/roonbridge.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 02:42:58 volumio systemd[1]: /lib/systemd/system/roonbridge.service:8: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 02:42:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 02:42:58 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 02:42:58 volumio sudo[12293]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:58 volumio volumio[1039]: info: Linked /data/plugins/user_interface/peppymeterbasic/alsa-lib/x86_64/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppymeterbasic/alsa-lib/libpeppyalsa.so Apr 14 02:42:58 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:58.056Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:58 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:58.057Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:58 volumio volumio[1039]: info: Linked /data/plugins/user_interface/peppymeterbasic/alsa-lib/x86_64/libpeppyalsa.so.0.0.0 to /data/plugins/user_interface/peppymeterbasic/alsa-lib/libpeppyalsa.so.0 Apr 14 02:42:58 volumio sudo[12314]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/chmod +x /data/plugins/user_interface/peppymeterbasic/startpeppymeterbasic.sh Apr 14 02:42:58 volumio sudo[12314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:42:58 volumio sudo[12314]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:58 volumio sudo[12135]: pam_unix(sudo:session): session closed for user root Apr 14 02:42:58 volumio volumio[1039]: Plugin install end detected on script Apr 14 02:42:58 volumio volumio[1039]: info: Install script completed Apr 14 02:42:58 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:58.674Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:58 volumio volumio[1039]: info: Adding reference to registry Apr 14 02:42:58 volumio volumio5-onboarding[1554]: time=2026-04-14T02:42:58.676Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 14 02:42:58 volumio volumio[1039]: info: Done installing plugin. Apr 14 02:42:58 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 02:42:58 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 14 02:42:58 volumio volumio[1039]: info: Folder /tmp/plugins removed Apr 14 02:42:58 volumio volumio[1039]: info: Folder /tmp/downloaded_plugin.zip removed Apr 14 02:42:58 volumio volumio[1039]: info: Folder /data/temp removed Apr 14 02:43:00 volumio volumio[1039]: info: Enabling plugin peppymeterbasic Apr 14 02:43:00 volumio volumio[1039]: info: Loading plugin "peppymeterbasic"... Apr 14 02:43:00 volumio volumio[1039]: info: Preparing to generate the ALSA configuration file Apr 14 02:43:00 volumio volumio[1039]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 14 02:43:00 volumio volumio[1039]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Apr 14 02:43:00 volumio volumio[1039]: info: Reading ALSA contributions from plugins. Apr 14 02:43:00 volumio volumio[1039]: info: Asound.conf file written Apr 14 02:43:00 volumio sudo[12334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 14 02:43:00 volumio sudo[12334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio sudo[12334]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: info: Output device has changed, restarting MPD Apr 14 02:43:00 volumio volumio[1039]: info: Output device has changed, restarting Shairport Sync Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 02:43:00 volumio sudo[12340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 02:43:00 volumio sudo[12342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 02:43:00 volumio volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 02:43:00 volumio volumio[1039]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 14 02:43:00 volumio sudo[12342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio sudo[12340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio sudo[12340]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: info: QobuzConnect: setDeactiveState invoked Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 02:43:00 volumio vtcs[4432]: [2026-04-14 02:43:00.266] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Apr 14 02:43:00 volumio vtcs[4432]: [2026-04-14 02:43:00.267] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Apr 14 02:43:00 volumio volumio[1039]: info: PLUGIN START: peppymeterbasic Apr 14 02:43:00 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 02:43:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 02:43:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 02:43:00 volumio sudo[12352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 14 02:43:00 volumio sudo[12352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 14 02:43:00 volumio volumio[1039]: info: Preparing to generate the ALSA configuration file Apr 14 02:43:00 volumio sudo[12356]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Apr 14 02:43:00 volumio sudo[12356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: Done. Apr 14 02:43:00 volumio sudo[12356]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 14 02:43:00 volumio sudo[12359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 14 02:43:00 volumio volumio[1039]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Apr 14 02:43:00 volumio volumio[1039]: info: Reading ALSA contributions from plugins. Apr 14 02:43:00 volumio volumio[1039]: info: snd_dummy loaded Apr 14 02:43:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 02:43:00 volumio volumio[1039]: info: MPD Permissions set Apr 14 02:43:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 02:43:00 volumio volumio[1039]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 14 02:43:00 volumio sudo[12374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 14 02:43:00 volumio sudo[12374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Apr 14 02:43:00 volumio systemd[1]: vtcs.service: Killing process 4435 (vtcs) with signal SIGKILL. Apr 14 02:43:00 volumio (udev-worker)[12372]: controlC7: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 7' failed with exit code 99. Apr 14 02:43:00 volumio systemd[1]: vtcs.service: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Apr 14 02:43:00 volumio systemd[1]: vtcs.service: Consumed 1.065s CPU time. Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio sudo[12374]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12359]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12352]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 02:43:00 volumio sudo[12383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 14 02:43:00 volumio sudo[12383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio sudo[12376]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 02:43:00 volumio sudo[12376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio sudo[12376]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: info: Starting Shairport Sync Apr 14 02:43:00 volumio sudo[12393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 02:43:00 volumio sudo[12393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 14 02:43:00 volumio qobuz-connect[4413]: 20260414 02:43:00.369 [4413.4413] INFO SampleApp: Stopping Local configuration server Apr 14 02:43:00 volumio volumio[1039]: info: Asound.conf file unchanged, so no further update is needed Apr 14 02:43:00 volumio volumio[1039]: info: Output device has changed, restarting MPD Apr 14 02:43:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 02:43:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 02:43:00 volumio systemd[1]: shairport-sync.service: Consumed 12.258s CPU time. Apr 14 02:43:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 02:43:00 volumio volumio[1039]: info: Output device has changed, restarting Shairport Sync Apr 14 02:43:00 volumio sudo[12393]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 02:43:00 volumio sudo[12396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 02:43:00 volumio sudo[12396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio sudo[12399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 02:43:00 volumio sudo[12396]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 02:43:00 volumio volumio[1039]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 02:43:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 02:43:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 02:43:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 02:43:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 02:43:00 volumio volumio[1039]: info: QobuzConnect: setDeactiveState invoked Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:00 volumio sudo[12425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 14 02:43:00 volumio sudo[12425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 02:43:00 volumio sudo[12425]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 14 02:43:00 volumio sudo[12437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: MPD Permissions set Apr 14 02:43:00 volumio volumio[1039]: info: Shairport-Sync Started Apr 14 02:43:00 volumio sudo[12422]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 02:43:00 volumio sudo[12422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 02:43:00 volumio volumio[1039]: (node:1039) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 14 02:43:00 volumio volumio[1039]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 14 02:43:00 volumio volumio[1039]: (node:1039) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 14 02:43:00 volumio volumio[1039]: (node:1039) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 14 02:43:00 volumio sudo[12422]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 14 02:43:00 volumio sudo[12430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio sudo[12437]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: (node:1039) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 14 02:43:00 volumio volumio[1039]: (node:1039) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio sudo[12442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 14 02:43:00 volumio sudo[12442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 02:43:00 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 02:43:00 volumio volumio[1039]: info: Starting Shairport Sync Apr 14 02:43:00 volumio sudo[12454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 02:43:00 volumio sudo[12454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 02:43:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 02:43:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 02:43:00 volumio sudo[12430]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 02:43:00 volumio sudo[12454]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: info: Shairport-Sync Started Apr 14 02:43:00 volumio mpd[12443]: 2026-04-14T02:43:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 02:43:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 02:43:00 volumio sudo[12399]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio sudo[12342]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:00 volumio volumio[1039]: error: MPD error: The expression evaluated to a falsy value: Apr 14 02:43:00 volumio volumio[1039]: assert.ok(self.idling) Apr 14 02:43:00 volumio volumio[1039]: error: The expression evaluated to a falsy value: Apr 14 02:43:00 volumio volumio[1039]: assert.ok(self.idling) Apr 14 02:43:00 volumio volumio[1039]: error: updateQueue error: null Apr 14 02:43:01 volumio qobuz-connect[4413]: 20260414 02:43:01.588 [4413.4413] INFO SampleApp: shat down connection on UNIX socket Apr 14 02:43:01 volumio volumio[1039]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Apr 14 02:43:01 volumio volumio[1039]: info: QobuzConnect: setDeactiveState invoked Apr 14 02:43:01 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:01 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 14 02:43:01 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 14 02:43:01 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 14 02:43:01 volumio sudo[12383]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:01 volumio sudo[12442]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:01 volumio volumio[1039]: info: Executing endpoint qc_getconfig Apr 14 02:43:01 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.623 [12475.12475] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.624 [12475.12475] INFO VolumeManager: [0x55b254548470]: Setting new playback volume: 75 Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.624 [12475.12475] INFO VolumeManager: [0x55b254548470]: Setting new mute state: 0 Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.624 [12475.12475] INFO AudioStreamManager: [0x55b254547fd0]: Setting new audio download buffer size: 1048576 Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.624 [12475.12475] INFO QobuzConnect: [0x55b254549480]: Client initialized! Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.624 [12475.12475] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Apr 14 02:43:01 volumio volumio[1039]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 14 02:43:01 volumio volumio[1039]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.628 [12475.12475] INFO LocalConfigManager: [0x55b254547ab0]: Starting Local Configuration server Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.628 [12475.12475] INFO SampleApp: Starting Local configuration server Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.628 [12475.12475] INFO SampleApp: Connected to UNIX socket client 0x55b25451ebb0 Apr 14 02:43:01 volumio qobuz-connect[12475]: 20260414 02:43:01.773 [12475.12475] INFO SampleApp: Playback volume changed: 75 Apr 14 02:43:01 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:03 volumio volumio[1039]: info: TidalConnect service stoped! Apr 14 02:43:03 volumio volumio[1039]: info: TidalConnect service stoped! Apr 14 02:43:03 volumio volumio[1039]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 14 02:43:03 volumio volumio[1039]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 14 02:43:03 volumio sudo[12493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 14 02:43:03 volumio sudo[12493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:03 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 14 02:43:03 volumio sudo[12493]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:03 volumio volumio[1039]: info: Executing endpoint tc_getconfig Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 14 02:43:03 volumio vtcs[12496]: STARTING TidalConnect services, version: 1.6.1 Apr 14 02:43:03 volumio vtcs[12496]: STARTED TidalConnect services. Apr 14 02:43:03 volumio volumio[1039]: info: Executing endpoint tc_connect Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 14 02:43:03 volumio volumio[1039]: info: Connecting to TidalConnect Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Apr 14 02:43:03 volumio volumio[1039]: info: CoreStateMachine::pushState Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Apr 14 02:43:03 volumio volumio[1039]: info: MRS: Pushing multiroomSync output update for this device Apr 14 02:43:03 volumio volumio[1039]: info: MRS: Pushing multiroomSync output Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:03 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Apr 14 02:43:03 volumio volumio[1039]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::servicePushState Apr 14 02:43:03 volumio volumio[1039]: info: CoreStateMachine::pushState Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::volumioPushState Apr 14 02:43:03 volumio volumio[1039]: info: MRS: Pushing multiroomSync output update for this device Apr 14 02:43:03 volumio volumio[1039]: info: MRS: Pushing multiroomSync output Apr 14 02:43:03 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:03 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Apr 14 02:43:03 volumio volumio[1039]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Apr 14 02:43:03 volumio volumio5-onboarding[1554]: time=2026-04-14T02:43:03.445Z level=WARN msg="received unknown player status" component=volumio status="" Apr 14 02:43:03 volumio volumio5-onboarding[1554]: time=2026-04-14T02:43:03.445Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:48344 @ 0xc0003be240" state=STATUS_STOPPED positionMs=799283 volume=41 Apr 14 02:43:03 volumio volumio5-onboarding[1554]: time=2026-04-14T02:43:03.445Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:48344 @ 0xc0003be240" id= title= Apr 14 02:43:03 volumio volumio5-onboarding[1554]: time=2026-04-14T02:43:03.445Z level=WARN msg="received unknown player status" component=volumio status="" Apr 14 02:43:03 volumio volumio5-onboarding[1554]: time=2026-04-14T02:43:03.445Z level=INFO msg="emitting player state changed event" component=server peer="192.168.2.232:48344 @ 0xc0003be240" state=STATUS_STOPPED positionMs=799283 volume=41 Apr 14 02:43:03 volumio volumio5-onboarding[1554]: time=2026-04-14T02:43:03.445Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.232:48344 @ 0xc0003be240" id= title= Apr 14 02:43:03 volumio volumio[1039]: info: Display-configuration --- Volumio status= timeout=120 noifplay=true screensavertype=dpms Apr 14 02:43:03 volumio volumio[1039]: info: Display-configuration --- Volumio status=undefined timeout=120 noifplay=true screensavertype=dpms Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: SPOTIFY VOLUME 40 Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: VOLUMIO VOLUME 41 Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: SPOTIFY VOLUME 40 Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: VOLUMIO VOLUME 41 Apr 14 02:43:03 volumio volumio[1039]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 14 02:43:03 volumio volumio[1039]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.DWvNi1cvvlckR9aRjg7Toh3kSBA2.58a8a01ec8066d245bc8929803ade2cc.state.status' Apr 14 02:43:03 volumio volumio[1039]: info: PeppyMeterBasic ---peppymeterbasic status Apr 14 02:43:03 volumio volumio[1039]: info: PeppyMeterBasic ---peppymeterbasic status undefined Apr 14 02:43:03 volumio volumio[1039]: info: TidalConnect service stoped! Apr 14 02:43:03 volumio volumio[1039]: info: TidalConnect service stoped! Apr 14 02:43:03 volumio volumio[1039]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 14 02:43:03 volumio volumio[1039]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 14 02:43:03 volumio sudo[12521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 14 02:43:03 volumio sudo[12521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 02:43:03 volumio sudo[12521]: pam_unix(sudo:session): session closed for user root Apr 14 02:43:05 volumio volumio[1039]: info: Executing endpoint metavolumio Apr 14 02:43:05 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 14 02:43:06 volumio volumio[1039]: info: TidalConnect service started! Apr 14 02:43:06 volumio volumio[1039]: info: TidalConnect service started! Apr 14 02:43:09 volumio volumio[1039]: info: CoreCommandRouter::volumioGetState Apr 14 02:43:09 volumio volumio[1039]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Apr 14 02:43:09 volumio volumio[1039]: info: CoreCommandRouter::volumioPlay Apr 14 02:43:09 volumio volumio[1039]: info: CoreStateMachine::play index undefined Apr 14 02:43:09 volumio volumio[1039]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 02:43:09 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Apr 14 02:43:09 volumio volumio[1039]: info: CoreStateMachine::startPlaybackTimer Apr 14 02:43:09 volumio volumio[1039]: info: CorePlayQueue::getTrack 0 Apr 14 02:43:09 volumio volumio[1039]: info: [soundcloud] clearAddPlayTrack: soundcloud/track@trackId=2086809642 Apr 14 02:43:10 volumio volumio[1039]: info: [soundcloud-testing] Available transcodings: [{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2086809642/3efffa70-d755-4ac2-a504-1bf5bb6e4f5a/stream/cbc-encrypted-hls","preset":"aac_160k","protocol":"cbc-encrypted-hls","mimeType":"audio/mp4; codecs=\"mp4a.40.2\"","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2086809642/3efffa70-d755-4ac2-a504-1bf5bb6e4f5a/stream/ctr-encrypted-hls","preset":"aac_160k","protocol":"ctr-encrypted-hls","mimeType":"audio/mp4; codecs=\"mp4a.40.2\"","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2086809642/88912e28-09b5-484e-932f-2b289b738e3b/stream/cbc-encrypted-hls","preset":"abr_sq","protocol":"cbc-encrypted-hls","mimeType":"audio/mpegurl","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2086809642/88912e28-09b5-484e-932f-2b289b738e3b/stream/ctr-encrypted-hls","preset":"abr_sq","protocol":"ctr-encrypted-hls","mimeType":"audio/mpegurl","quality":"sq"},{"url":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2086809642/6ae58c65-e1be-4b51-839a-10de72825b18/stream/hls","preset":"mp3_1_0","protocol":"hls","mimeType":"audio/mpeg","quality":"sq"}] Apr 14 02:43:10 volumio volumio[1039]: info: [soundcloud-testing] Chosen transcoding: {"format":"mp3_1_0+hls","codec":"mp3","protocol":"hls","bitrate":"128 kbps","transcodingUrl":"https://api-v2.soundcloud.com/media/soundcloud:tracks:2086809642/6ae58c65-e1be-4b51-839a-10de72825b18/stream/hls"} Apr 14 02:43:10 volumio volumio[1039]: info: [soundcloud] [mpv] mpv process spawned Apr 14 02:43:10 volumio volumio[1039]: info: [soundcloud] Going to start mpv for playback Apr 14 02:43:10 volumio volumio[1039]: info: [soundcloud] [mpv] (PID: 12546) /bin/sh: 1: mpv: not found Apr 14 02:43:10 volumio volumio[1039]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 02:43:10 volumio volumio[1039]: TypeError: Cannot read properties of null (reading 'reset') Apr 14 02:43:10 volumio volumio[1039]: at /data/plugins/music_service/soundcloud/node_modules/volumio-ext-players/dist/mpv/MPVService.js:170:48 Apr 14 02:43:10 volumio volumio[1039]: at ChildProcess. (/data/plugins/music_service/soundcloud/node_modules/volumio-ext-players/dist/mpv/MPVService.js:184:19) Apr 14 02:43:10 volumio volumio[1039]: at ChildProcess.emit (node:events:514:28) Apr 14 02:43:10 volumio volumio[1039]: at maybeClose (node:internal/child_process:1105:16) Apr 14 02:43:10 volumio volumio[1039]: at Socket. (node:internal/child_process:457:11) Apr 14 02:43:10 volumio volumio[1039]: at Socket.emit (node:events:514:28) Apr 14 02:43:10 volumio volumio[1039]: at Pipe. (node:net:337:12) Apr 14 02:43:10 volumio volumio[1039]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 02:43:10 volumio sudo[12561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 02:42' Apr 14 02:43:10 volumio sudo[12561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"