Apr 03 16:50:00 volumio-bonfim volumio[5017]: info: Selecting previously unselected package libexif12:armhf. Apr 03 16:50:00 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:00.015Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:02 volumio-bonfim volumio[5017]: [620B blob data] Apr 03 16:50:02 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:02.165Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:02 volumio-bonfim volumio[5017]: info: Preparing to unpack .../libexif12_0.6.24-1+b2_armhf.deb ... Apr 03 16:50:02 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:02.174Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:02 volumio-bonfim volumio[5017]: info: Unpacking libexif12:armhf (0.6.24-1+b2) ... Apr 03 16:50:02 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:02.186Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:02 volumio-bonfim volumio[5017]: info: Selecting previously unselected package minidlna. Apr 03 16:50:02 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:02.381Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:02 volumio-bonfim volumio[5017]: info: Preparing to unpack .../minidlna_1.3.0+dfsg-2.2+deb12u1_armhf.deb ... Apr 03 16:50:02 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:02.390Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:02 volumio-bonfim volumio[5017]: info: Unpacking minidlna (1.3.0+dfsg-2.2+deb12u1) ... Apr 03 16:50:02 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:02.402Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:03 volumio-bonfim volumio[5017]: info: Setting up libexif12:armhf (0.6.24-1+b2) ... Apr 03 16:50:03 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:03.543Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:03 volumio-bonfim volumio[5017]: info: Setting up minidlna (1.3.0+dfsg-2.2+deb12u1) ... Apr 03 16:50:03 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:03.578Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:03 volumio-bonfim groupadd[5869]: group added to /etc/group: name=minidlna, GID=116 Apr 03 16:50:03 volumio-bonfim groupadd[5869]: group added to /etc/gshadow: name=minidlna Apr 03 16:50:03 volumio-bonfim groupadd[5869]: new group: name=minidlna, GID=116 Apr 03 16:50:03 volumio-bonfim useradd[5875]: new user: name=minidlna, UID=112, GID=116, home=/var/lib/minidlna, shell=/usr/sbin/nologin, from=none Apr 03 16:50:03 volumio-bonfim chfn[5882]: changed user 'minidlna' information Apr 03 16:50:04 volumio-bonfim volumio[5017]: info: insserv: Script `ssh' has overlapping Default-Start and Default-Stop runlevels (2 3 4 5) and (2 3 4 5). This should be fixed. Apr 03 16:50:04 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:04.099Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:04 volumio-bonfim systemd[1]: Reloading. Apr 03 16:50:05 volumio-bonfim volumio[5017]: info: Created symlink /etc/systemd/system/multi-user.target.wants/minidlna.service → /lib/systemd/system/minidlna.service. Apr 03 16:50:05 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:05.733Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:05 volumio-bonfim systemd[1]: Reloading. Apr 03 16:50:06 volumio-bonfim systemd[1]: Starting fstrim.service - Discard unused blocks on filesystems from /etc/fstab... Apr 03 16:50:06 volumio-bonfim systemd[1]: Started minidlna.service - MiniDLNA lightweight DLNA/UPnP-AV server. Apr 03 16:50:06 volumio-bonfim volumio[5017]: info: Processing triggers for libc-bin (2.36-9+rpt2+deb12u13) ... Apr 03 16:50:06 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:06.841Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:07 volumio-bonfim fstrim[5940]: /boot: 273.3 MiB (286588928 bytes) trimmed on /dev/mmcblk0p1 Apr 03 16:50:07 volumio-bonfim systemd[1]: fstrim.service: Deactivated successfully. Apr 03 16:50:07 volumio-bonfim systemd[1]: Finished fstrim.service - Discard unused blocks on filesystems from /etc/fstab. Apr 03 16:50:08 volumio-bonfim systemd[1]: Reloading. Apr 03 16:50:09 volumio-bonfim systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Apr 03 16:50:09 volumio-bonfim systemd[1]: Reloading. Apr 03 16:50:10 volumio-bonfim systemd[1]: Reloading. Apr 03 16:50:11 volumio-bonfim systemd[1]: Stopping minidlna.service - MiniDLNA lightweight DLNA/UPnP-AV server... Apr 03 16:50:11 volumio-bonfim systemd[1]: minidlna.service: Deactivated successfully. Apr 03 16:50:11 volumio-bonfim systemd[1]: Stopped minidlna.service - MiniDLNA lightweight DLNA/UPnP-AV server. Apr 03 16:50:12 volumio-bonfim volumio[5017]: info: Creating systemd unit /etc/systemd/system/minidlna.service Apr 03 16:50:12 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:12.474Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:12 volumio-bonfim systemd[1]: Reloading. Apr 03 16:50:13 volumio-bonfim systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Setting values for "network_interface" and "model_number" in /data/plugins/music_service/minidlna/config.json Apr 03 16:50:13 volumio-bonfim systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Apr 03 16:50:13 volumio-bonfim systemd[1]: apt-daily-upgrade.service: Consumed 1.205s CPU time. Apr 03 16:50:13 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:13.401Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Setting permissions to MiniDLNA folders Apr 03 16:50:13 volumio-bonfim sudo[5651]: pam_unix(sudo:session): session closed for user root Apr 03 16:50:13 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:13.542Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Install script completed Apr 03 16:50:13 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:13.555Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Adding reference to registry Apr 03 16:50:13 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:13.561Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Done installing plugin. Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:50:13 volumio-bonfim volumio[5017]: Plugin install end detected on script Apr 03 16:50:13 volumio-bonfim volumio[5017]: info: Folder /data/temp removed Apr 03 16:50:15 volumio-bonfim volumio[5017]: info: Enabling plugin minidlna Apr 03 16:50:15 volumio-bonfim volumio[5017]: info: Loading plugin "minidlna"... Apr 03 16:50:15 volumio-bonfim volumio[5017]: info: Applying required configuration parameters for plugin minidlna Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: PLUGIN START: minidlna Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: Loading i18n strings for locale en Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: minidlna: Found miniDLNA version 1.3.0 Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: minidlna: /data/minidlna.conf written Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: minidlna: Starting minidlna.service Apr 03 16:50:16 volumio-bonfim sudo[6138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Apr 03 16:50:16 volumio-bonfim sudo[6138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 16:50:16 volumio-bonfim systemd[1]: Started minidlna.service - MiniDLNA lightweight DLNA/UPnP-AV server. Apr 03 16:50:16 volumio-bonfim sudo[6138]: pam_unix(sudo:session): session closed for user root Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: minidlna: systemctl start minidlna.service succeeded. Apr 03 16:50:16 volumio-bonfim volumio[5017]: info: Done. Apr 03 16:50:31 volumio-bonfim volumio[5017]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/motherearthradio/volumio/bookworm/armhf Apr 03 16:50:31 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:31.733Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/motherearthradio/volumio/bookworm/armhf Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.013Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.044Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Check plugin dependencies Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.069Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Checking if plugin already exists Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.075Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Rename folder Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.102Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Move to category Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.375Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Checking if install.sh is present Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Executing install.sh Apr 03 16:50:33 volumio-bonfim sudo[6195]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/motherearthradio/install.sh Apr 03 16:50:33 volumio-bonfim sudo[6195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Installing motherearthradio Dependencies Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.458Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim sudo[6195]: pam_unix(sudo:session): session closed for user root Apr 03 16:50:33 volumio-bonfim volumio[5017]: Plugin install end detected on script Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Install script completed Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.467Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Adding reference to registry Apr 03 16:50:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:33.472Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Done installing plugin. Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:50:33 volumio-bonfim volumio[5017]: info: Folder /data/temp removed Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: Enabling plugin motherearthradio Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: Loading plugin "motherearthradio"... Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: PLUGIN START: motherearthradio Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: [1775231435302] CoreMusicLibrary::Adding element Mother Earth Radio Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 16:50:35 volumio-bonfim volumio[5017]: Cannot find translation for source Mother Earth Radio Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: [MER] Plugin started (SSE mode) Apr 03 16:50:35 volumio-bonfim volumio[5017]: info: Done. Apr 03 16:50:48 volumio-bonfim volumio[5017]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/podcast/volumio/bookworm/armhf Apr 03 16:50:48 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:48.348Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/podcast/volumio/bookworm/armhf Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.475Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Check plugin dependencies Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.569Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.590Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Checking if plugin already exists Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.595Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Rename folder Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Move to category Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.615Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.929Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Checking if install.sh is present Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Executing install.sh Apr 03 16:50:49 volumio-bonfim sudo[6233]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/podcast/install.sh Apr 03 16:50:49 volumio-bonfim sudo[6233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 16:50:49 volumio-bonfim sudo[6233]: pam_unix(sudo:session): session closed for user root Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Installing Podcast plugin Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.974Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: Plugin install end detected on script Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Install script completed Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.986Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Adding reference to registry Apr 03 16:50:49 volumio-bonfim systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. Apr 03 16:50:49 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:50:49.995Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:50:49 volumio-bonfim volumio[5017]: info: Done installing plugin. Apr 03 16:50:49 volumio-bonfim systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. Apr 03 16:50:50 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 16:50:50 volumio-bonfim systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. Apr 03 16:50:50 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 16:50:50 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:50:50 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:50:50 volumio-bonfim volumio[5017]: info: Folder /data/temp removed Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: Enabling plugin podcast Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: Loading plugin "podcast"... Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: ControllerPodcast::constructor Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: PLUGIN START: podcast Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: [1775231451394] CoreMusicLibrary::Adding element Podcast Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 16:50:51 volumio-bonfim volumio[5017]: Cannot find translation for source Mother Earth Radio Apr 03 16:50:51 volumio-bonfim volumio[5017]: Cannot find translation for source Podcast Apr 03 16:50:51 volumio-bonfim volumio[5017]: info: Done. Apr 03 16:51:16 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 16:51:33 volumio-bonfim volumio[5017]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Apr 03 16:51:33 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:33.352Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:51:35 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:35.009Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:35 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:35.541Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: Check plugin dependencies Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 16:51:35 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:35.582Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: Checking if plugin already exists Apr 03 16:51:35 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:35.587Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: Rename folder Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:51:35 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:35.606Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:35 volumio-bonfim volumio[5017]: info: Move to category Apr 03 16:51:36 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:36.692Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:36 volumio-bonfim volumio[5017]: info: Checking if install.sh is present Apr 03 16:51:36 volumio-bonfim volumio[5017]: info: Executing install.sh Apr 03 16:51:36 volumio-bonfim sudo[6338]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Apr 03 16:51:36 volumio-bonfim sudo[6338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 16:51:36 volumio-bonfim volumio[5017]: info: Installing Go-librespot Apr 03 16:51:36 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:36.732Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:36 volumio-bonfim volumio[5017]: info: Checking old vollibrespot installs Apr 03 16:51:36 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:36.744Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:36 volumio-bonfim systemd[1]: Reloading. Apr 03 16:51:37 volumio-bonfim volumio[5017]: info: Downloading daemon Apr 03 16:51:37 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:37.909Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:37 volumio-bonfim systemd[1]: Starting apt-daily.service - Daily apt download activities... Apr 03 16:51:39 volumio-bonfim volumio[5017]: info: Creating directories Apr 03 16:51:39 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:39.238Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:39 volumio-bonfim volumio[5017]: info: Creating data directory Apr 03 16:51:39 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:39.250Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:39 volumio-bonfim volumio[5017]: info: Creating Start Script Apr 03 16:51:39 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:39.257Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:39 volumio-bonfim systemd[1]: Reloading. Apr 03 16:51:40 volumio-bonfim sudo[6338]: pam_unix(sudo:session): session closed for user root Apr 03 16:51:40 volumio-bonfim systemd[1]: apt-daily.service: Deactivated successfully. Apr 03 16:51:40 volumio-bonfim systemd[1]: Finished apt-daily.service - Daily apt download activities. Apr 03 16:51:40 volumio-bonfim systemd[1]: apt-daily.service: Consumed 1.252s CPU time. Apr 03 16:51:40 volumio-bonfim volumio[5017]: Plugin install end detected on script Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: Install script completed Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: Adding reference to registry Apr 03 16:51:40 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:40.229Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:40 volumio-bonfim volumio5-onboarding[1894]: time=2026-04-03T15:51:40.232Z level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: Done installing plugin. Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: Folder /tmp/plugins removed Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: Folder /tmp/downloaded_plugin.zip removed Apr 03 16:51:40 volumio-bonfim volumio[5017]: info: Folder /data/temp removed Apr 03 16:51:41 volumio-bonfim volumio[5017]: info: Enabling plugin spop Apr 03 16:51:41 volumio-bonfim volumio[5017]: info: Loading plugin "spop"... Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: PLUGIN START: spop Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: Creating Spotify config file Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: Done. Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: Spotify config file written Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: No need to fix Spotify hosts Apr 03 16:51:42 volumio-bonfim sudo[6455]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 16:51:42 volumio-bonfim sudo[6455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 03 16:51:42 volumio-bonfim 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 03 16:51:42 volumio-bonfim 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 03 16:51:42 volumio-bonfim systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 16:51:42 volumio-bonfim go-librespot[6457]: go-librespot daemon starting... Apr 03 16:51:42 volumio-bonfim sudo[6455]: pam_unix(sudo:session): session closed for user root Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=info msg="running go-librespot 0.7.1" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="no app state found" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="stored credentials not found" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=info msg="generated new device id: fb3a20cd354851b862373841877e61e8c52b73b8" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: New Spotify access tokenBQCl-QKcbf... Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 03 16:51:42 volumio-bonfim volumio[5017]: SPOTIFY: User informations: {"country":"ES","display_name":"Caye Kalea del Swing","email":"mcayetanadiez@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1177473549"},"followers":{"href":null,"total":28},"href":"https://api.spotify.com/v1/users/1177473549","id":"1177473549","images":[{"height":300,"url":"https://scontent-tpe1-1.xx.fbcdn.net/v/t39.30808-1/468638061_10161522921491693_2108758416877532220_n.jpg?stp=dst-jpg_s320x320_tt6&_nc_cat=111&ccb=1-7&_nc_sid=08baa4&_nc_ohc=cVfGIwXVqJUQ7kNvwGzjXWz&_nc_oc=AdrrhAiAWtUZACbPRISwvK5qJjZYWa1oK2Lfd0yu-RIRugkcO8UEtgBhHB6Vl8g2uhonM6rtJVva0K1J7uC2UMDk&_nc_zt=24&_nc_ht=scontent-tpe1-1.xx&edm=AP4hL3IEAAAA&_nc_gid=MuzxtF1t5fb39hld7OzIuQ&_nc_tpa=Q5bMBQEvxfG-4PHeRg6IIPxUJ7CKl40jHGkIIhClipb5wfwBJTjT3mTkH3czw-7AjlKxJQaL5hRS&oh=00_Af3MQUfvsrf10hBxKNlC8DQjwiMebjfXFw1n8xfhEti1Yg&oe=69D547DF","width":300},{"height":64,"url":"https://scontent-tpe1-1.xx.fbcdn.net/v/t39.30808-1/468638061_10161522921491693_2108758416877532220_n.jpg?stp=cp0_dst-jpg_s50x50_tt6&_nc_cat=111&ccb=1-7&_nc_sid=28885b&_nc_ohc=cVfGIwXVqJUQ7kNvwGzjXWz&_nc_oc=AdrrhAiAWtUZACbPRISwvK5qJjZYWa1oK2Lfd0yu-RIRugkcO8UEtgBhHB6Vl8g2uhonM6rtJVva0K1J7uC2UMDk&_nc_zt=24&_nc_ht=scontent-tpe1-1.xx&edm=AP4hL3IEAAAA&_nc_gid=MuzxtF1t5fb39hld7OzIuQ&_nc_tpa=Q5bMBQFg7eJHHnGXKYgG5NmCU4odbIq8EpHIJ65hUNoNAvkLEL6KcJ1BykAtqyL8J_YH5iQIHlE0&oh=00_Af2bGjqOrrArB2t8D-ZfmrdXuy31qdZYwKWTMCD12ZBfaA&oe=69D547DF","width":64}],"product":"premium","type":"user","uri":"spotify:user:1177473549"} Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: Spotify Successfully logged in Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: [1775231502745] CoreMusicLibrary::Adding element Spotify Apr 03 16:51:42 volumio-bonfim volumio[5017]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 16:51:42 volumio-bonfim volumio[5017]: Cannot find translation for source Mother Earth Radio Apr 03 16:51:42 volumio-bonfim volumio[5017]: Cannot find translation for source Podcast Apr 03 16:51:42 volumio-bonfim volumio[5017]: Cannot find translation for source Spotify Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=info msg="zeroconf server listening on port 43705" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="obtained new client token: AAAh1BvYcwCQpCzaFzJHlvI6PRrzNBUl+NyxDcfDHGMOtjHAw27w0/z4m8PKwTtCz3R/wvEpPiatvIugsgyesby4Gbsg3EOTPEDXSYBqL6/wWEMP0jhwuosh6G2xwOovrrajAk0pGZOuQEoLE1fFU/dVr28vOKY8AJ7XvJUSVjN2HBQU6GYKuXhEtWj7G/bqLKY/zOc2yV6bPRzp0hiW+FLnl/uaXKihSY1qbcES3CCCuiBuBnItsExf" Apr 03 16:51:42 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:42+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=debug msg="completed challenge" Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=debug msg="completed challenge" Apr 03 16:51:43 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:43+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:44 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:44+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 03 16:51:44 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:44+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:44 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:44+01:00" level=debug msg="completed challenge" Apr 03 16:51:44 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:44+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:44 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:44+01:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 03 16:51:45 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:45+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:45 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:45+01:00" level=debug msg="completed challenge" Apr 03 16:51:45 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:45+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:45 volumio-bonfim volumio[5017]: info: go-librespot daemon successfully initialized Apr 03 16:51:45 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:45+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 03 16:51:45 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:45+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:45 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:45+01:00" level=debug msg="completed challenge" Apr 03 16:51:46 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:46+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:46 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:46+01:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 03 16:51:47 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:47+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:47 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:47+01:00" level=debug msg="completed challenge" Apr 03 16:51:47 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:47+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:47 volumio-bonfim go-librespot[6458]: time="2026-04-03T16:51:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:47 volumio-bonfim systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 03 16:51:47 volumio-bonfim systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 03 16:51:48 volumio-bonfim volumio[5017]: info: Initializing connection to go-librespot Websocket Apr 03 16:51:48 volumio-bonfim volumio[5017]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 03 16:51:50 volumio-bonfim systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 03 16:51:50 volumio-bonfim systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 03 16:51:50 volumio-bonfim systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 03 16:51:50 volumio-bonfim go-librespot[6487]: go-librespot daemon starting... Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=info msg="running go-librespot 0.7.1" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="app state loaded" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="stored credentials not found" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=info msg="zeroconf server listening on port 41515" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="obtained new client token: AAC2/rw3P6Sug3PjOVKyivjY9GYc0/cKrnTLWUdxJBtS/iT5fIzx2Phs1t6hzvzC4DX9uQgX+8WjGQ8e2IcEv/2k90GX6QJ6HhFp+WErh0Fa7ti795VLvknH7HYg5Vg8jNVFEVYTNa2/FmWRKrBigW41umLHX6Hm00lAwyNEkZM3IjBLtJVwlGXf0+WF1esQwLDfg8rW2aDjTpfX90OD+XyI4hsKR32ogyXuKaR1l84mefmaEHY+ISUe" Apr 03 16:51:50 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:50+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 03 16:51:51 volumio-bonfim volumio[5017]: info: Initializing connection to go-librespot Websocket Apr 03 16:51:51 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:51+01:00" level=debug msg="new websocket client" Apr 03 16:51:51 volumio-bonfim volumio[5017]: info: Connection to go-librespot Websocket established Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=debug msg="completed challenge" Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=debug msg="completed challenge" Apr 03 16:51:52 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:52+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:53 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:53+01:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 03 16:51:53 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:53+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:53 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:53+01:00" level=debug msg="completed challenge" Apr 03 16:51:53 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:53+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=debug msg="completed challenge" Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:54 volumio-bonfim volumio[5017]: info: Getting Spotify volume Apr 03 16:51:54 volumio-bonfim volumio[5017]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 03 16:51:54 volumio-bonfim volumio[5017]: info: CoreCommandRouter::volumioGetState Apr 03 16:51:54 volumio-bonfim volumio[5017]: info: CorePlayQueue::getTrack 0 Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:54 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:54+01:00" level=debug msg="completed challenge" Apr 03 16:51:55 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:55+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:55 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:55+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Apr 03 16:51:55 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:55+01:00" level=debug msg="completed keyexchange" Apr 03 16:51:55 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:55+01:00" level=debug msg="completed challenge" Apr 03 16:51:55 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:55+01:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:55 volumio-bonfim go-librespot[6488]: time="2026-04-03T16:51:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Apr 03 16:51:55 volumio-bonfim volumio[5017]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 16:51:55 volumio-bonfim volumio[5017]: Error: socket hang up Apr 03 16:51:55 volumio-bonfim volumio[5017]: at connResetException (node:internal/errors:720:14) Apr 03 16:51:55 volumio-bonfim volumio[5017]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 03 16:51:55 volumio-bonfim volumio[5017]: at Socket.emit (node:events:526:35) Apr 03 16:51:55 volumio-bonfim volumio[5017]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 03 16:51:55 volumio-bonfim volumio[5017]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 03 16:51:55 volumio-bonfim volumio[5017]: code: 'ECONNRESET', Apr 03 16:51:55 volumio-bonfim volumio[5017]: response: undefined Apr 03 16:51:55 volumio-bonfim volumio[5017]: } Apr 03 16:51:55 volumio-bonfim volumio[5017]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 16:51:55 volumio-bonfim systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 03 16:51:55 volumio-bonfim systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 03 16:51:56 volumio-bonfim sudo[6511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-03 16:50' Apr 03 16:51:56 volumio-bonfim sudo[6511]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"