Feb 23 15:21:28 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:21:28 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 15:21:33 volumio4 volumio[1270]: info: Enabling plugin now_playing Feb 23 15:21:33 volumio4 volumio[1270]: info: Loading plugin "now_playing"... Feb 23 15:21:34 volumio4 volumio[1270]: info: PLUGIN START: now_playing Feb 23 15:21:34 volumio4 volumio[1270]: info: [now-playing] ConfigUpdater: config is up to date. Feb 23 15:21:34 volumio4 volumio[1270]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): OpenWeatherMap API-sleutel niet geconfigureerd. Voeg deze toe in de weerservice-instellingen. Feb 23 15:21:34 volumio4 volumio[1270]: info: [now-playing] App is listening on port 4004. Feb 23 15:21:34 volumio4 volumio[1270]: info: [now-playing] Backing up /opt/volumiokiosk.sh to /home/volumio/.now_playing/volumiokiosk.sh.bak Feb 23 15:21:34 volumio4 sudo[4558]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sed -i s/localhost:3000/localhost:4004/g /opt/volumiokiosk.sh Feb 23 15:21:34 volumio4 sudo[4558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:21:34 volumio4 sudo[4558]: pam_unix(sudo:session): session closed for user root Feb 23 15:21:34 volumio4 volumio[1270]: [sudo] password for volumio: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl status volumio-kiosk Feb 23 15:21:34 volumio4 sudo[4562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status volumio-kiosk Feb 23 15:21:34 volumio4 sudo[4562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:21:34 volumio4 sudo[4562]: pam_unix(sudo:session): session closed for user root Feb 23 15:21:34 volumio4 volumio[1270]: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl restart volumio-kiosk Feb 23 15:21:34 volumio4 sudo[4573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk Feb 23 15:21:34 volumio4 sudo[4573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:21:34 volumio4 startx[1754]: xinit: connection to X server lost Feb 23 15:21:34 volumio4 startx[1754]: Feb 23 15:21:34 volumio4 systemd[1]: Stopping volumio-kiosk.service - Volumio Kiosk... Feb 23 15:21:35 volumio4 startx[1754]: waiting for X server to shut down Feb 23 15:21:35 volumio4 startx[1756]: (II) Server terminated successfully (0). Closing log file. Feb 23 15:21:35 volumio4 startx[1754]: xinit: unexpected signal 15 Feb 23 15:21:35 volumio4 systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Feb 23 15:21:35 volumio4 systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Feb 23 15:21:35 volumio4 systemd[1]: Stopped volumio-kiosk.service - Volumio Kiosk. Feb 23 15:21:35 volumio4 systemd[1]: volumio-kiosk.service: Consumed 27.402s CPU time. Feb 23 15:21:35 volumio4 systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Feb 23 15:21:35 volumio4 sudo[4573]: pam_unix(sudo:session): session closed for user root Feb 23 15:21:35 volumio4 volumio[1270]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 23 15:21:35 volumio4 volumio[1270]: info: Done. Feb 23 15:21:36 volumio4 startx[4613]: X.Org X Server 1.21.1.7 Feb 23 15:21:36 volumio4 startx[4613]: X Protocol Version 11, Revision 0 Feb 23 15:21:36 volumio4 startx[4613]: Current Operating System: Linux volumio4 6.12.47-v7l+ #1904 SMP Mon Sep 15 13:08:10 BST 2025 armv7l Feb 23 15:21:36 volumio4 startx[4613]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 snd_bcm2835.enable_hdmi=0 snd_bcm2835.enable_hdmi=0 video=HDMI-A-1:800x1920M@60D numa=fake=2 system_heap.max_order=0 smsc95xx.macaddr=E4:5F:01:29:09:49 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=7e9efb31-d81e-40e6-b369-17d6be2a2543 imgfile=/volumio_current.sqsh bootpart=UUID=41F4-3F60 datapart=UUID=d86abd49-9ab6-4e7d-8df3-6405c27b7066 uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Feb 23 15:21:36 volumio4 startx[4613]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Feb 23 15:21:36 volumio4 startx[4613]: Current version of pixman: 0.44.0 Feb 23 15:21:36 volumio4 startx[4613]: Before reporting problems, check http://wiki.x.org Feb 23 15:21:36 volumio4 startx[4613]: to make sure that you have the latest version. Feb 23 15:21:36 volumio4 startx[4613]: Markers: (--) probed, (**) from config file, (==) default setting, Feb 23 15:21:36 volumio4 startx[4613]: (++) from command line, (!!) notice, (II) informational, Feb 23 15:21:36 volumio4 startx[4613]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Feb 23 15:21:36 volumio4 startx[4613]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Feb 23 15:21:36 2026 Feb 23 15:21:36 volumio4 startx[4613]: (==) Using config directory: "/etc/X11/xorg.conf.d" Feb 23 15:21:36 volumio4 startx[4613]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Feb 23 15:21:38 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:21:38 volumio4 volumio[1270]: info: Discovery: Getting this device information Feb 23 15:21:38 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:38 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:38 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:21:39 volumio4 volumio[1270]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 23 15:21:39 volumio4 volumio[1270]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): OpenWeatherMap API-sleutel niet geconfigureerd. Voeg deze toe in de weerservice-instellingen. Feb 23 15:21:39 volumio4 volumio[1270]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Kon weer niet ophalen: OpenWeatherMap API-sleutel niet geconfigureerd. Voeg deze toe in de weerservice-instellingen. Feb 23 15:21:39 volumio4 volumio[1270]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:108:25) Feb 23 15:21:39 volumio4 volumio[1270]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 23 15:21:39 volumio4 volumio[1270]: at async Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:126:28) Feb 23 15:21:39 volumio4 volumio[1270]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Feb 23 15:21:39 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Feb 23 15:21:39 volumio4 volumio[1270]: info: Listing playlists Feb 23 15:21:39 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetQueue Feb 23 15:21:39 volumio4 volumio[1270]: info: CoreStateMachine::getQueue Feb 23 15:21:39 volumio4 volumio[1270]: info: CorePlayQueue::getQueue Feb 23 15:21:39 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetVisibleSources Feb 23 15:21:39 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 15:21:39 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:39 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:47 volumio4 sudo[4805]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sed -i s/localhost:4004/localhost:3000/g /opt/volumiokiosk.sh Feb 23 15:21:47 volumio4 sudo[4805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:21:47 volumio4 sudo[4805]: pam_unix(sudo:session): session closed for user root Feb 23 15:21:47 volumio4 volumio[1270]: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl status volumio-kiosk Feb 23 15:21:47 volumio4 sudo[4808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status volumio-kiosk Feb 23 15:21:47 volumio4 sudo[4808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:21:47 volumio4 sudo[4808]: pam_unix(sudo:session): session closed for user root Feb 23 15:21:47 volumio4 volumio[1270]: info: [now-playing] Executing /usr/bin/sudo /bin/systemctl restart volumio-kiosk Feb 23 15:21:47 volumio4 sudo[4811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk Feb 23 15:21:47 volumio4 sudo[4811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:21:47 volumio4 startx[4612]: xinit: connection to X server lost Feb 23 15:21:47 volumio4 startx[4612]: Feb 23 15:21:47 volumio4 systemd[1]: Stopping volumio-kiosk.service - Volumio Kiosk... Feb 23 15:21:47 volumio4 startx[4612]: waiting for X server to shut down Feb 23 15:21:47 volumio4 startx[4613]: (II) Server terminated successfully (0). Closing log file. Feb 23 15:21:48 volumio4 startx[4612]: xinit: unexpected signal 15 Feb 23 15:21:48 volumio4 systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Feb 23 15:21:48 volumio4 systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Feb 23 15:21:48 volumio4 systemd[1]: Stopped volumio-kiosk.service - Volumio Kiosk. Feb 23 15:21:48 volumio4 systemd[1]: volumio-kiosk.service: Consumed 6.808s CPU time. Feb 23 15:21:48 volumio4 systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Feb 23 15:21:48 volumio4 sudo[4811]: pam_unix(sudo:session): session closed for user root Feb 23 15:21:48 volumio4 volumio[1270]: warn: [now-playing] MyBackgroundMonitor stopped Feb 23 15:21:48 volumio4 volumio[1270]: info: Disabling plugin now_playing Feb 23 15:21:48 volumio4 volumio[1270]: info: Done. Feb 23 15:21:48 volumio4 startx[4840]: X.Org X Server 1.21.1.7 Feb 23 15:21:48 volumio4 startx[4840]: X Protocol Version 11, Revision 0 Feb 23 15:21:48 volumio4 startx[4840]: Current Operating System: Linux volumio4 6.12.47-v7l+ #1904 SMP Mon Sep 15 13:08:10 BST 2025 armv7l Feb 23 15:21:48 volumio4 startx[4840]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 snd_bcm2835.enable_hdmi=0 snd_bcm2835.enable_hdmi=0 video=HDMI-A-1:800x1920M@60D numa=fake=2 system_heap.max_order=0 smsc95xx.macaddr=E4:5F:01:29:09:49 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=7e9efb31-d81e-40e6-b369-17d6be2a2543 imgfile=/volumio_current.sqsh bootpart=UUID=41F4-3F60 datapart=UUID=d86abd49-9ab6-4e7d-8df3-6405c27b7066 uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Feb 23 15:21:48 volumio4 startx[4840]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Feb 23 15:21:48 volumio4 startx[4840]: Current version of pixman: 0.44.0 Feb 23 15:21:48 volumio4 startx[4840]: Before reporting problems, check http://wiki.x.org Feb 23 15:21:48 volumio4 startx[4840]: to make sure that you have the latest version. Feb 23 15:21:48 volumio4 startx[4840]: Markers: (--) probed, (**) from config file, (==) default setting, Feb 23 15:21:48 volumio4 startx[4840]: (++) from command line, (!!) notice, (II) informational, Feb 23 15:21:48 volumio4 startx[4840]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Feb 23 15:21:48 volumio4 startx[4840]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Feb 23 15:21:48 2026 Feb 23 15:21:48 volumio4 startx[4840]: (==) Using config directory: "/etc/X11/xorg.conf.d" Feb 23 15:21:48 volumio4 startx[4840]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Feb 23 15:21:52 volumio4 volumio[1270]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 23 15:21:53 volumio4 volumio[1270]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetVisibleSources Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:53 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 23 15:21:53 volumio4 volumio[1270]: info: Received Get System Info Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:21:53 volumio4 volumio[1270]: info: Discovery: Getting this device information Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:53 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:53 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:53 volumio4 volumio[1270]: info: Listing playlists Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 23 15:21:53 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 15:21:54 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 23 15:21:55 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:21:55 volumio4 volumio[1270]: info: Received Get System Info Feb 23 15:21:55 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:21:55 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:21:55 volumio4 volumio[1270]: info: Discovery: Getting this device information Feb 23 15:21:55 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:55 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:55 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:21:55 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 23 15:21:56 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:21:56 volumio4 volumio[1270]: info: Received Get System Info Feb 23 15:21:56 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:21:56 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:21:56 volumio4 volumio[1270]: info: Discovery: Getting this device information Feb 23 15:21:56 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:21:56 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:21:56 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:22:03 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 15:22:11 volumio4 volumio[1270]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 23 15:22:11 volumio4 volumio[1270]: info: Received Get System Version Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 15:22:11 volumio4 volumio[1270]: info: Received Get System Info Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:22:11 volumio4 volumio[1270]: info: Discovery: Getting this device information Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:22:11 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:22:11 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:22:31 volumio4 nmbd[1136]: [2026/02/23 15:22:31.539970, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 23 15:22:31 volumio4 nmbd[1136]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.163 for name WORKGROUP<1d>. Feb 23 15:22:31 volumio4 nmbd[1136]: This response was from IP 192.168.1.228, reporting an IP address of 192.168.1.228. Feb 23 15:22:38 volumio4 volumio[1270]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/spop/volumio/bookworm/armhf Feb 23 15:22:38 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:38.126+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:40 volumio4 volumio[1270]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/spop/volumio/bookworm/armhf Feb 23 15:22:40 volumio4 volumio[1270]: info: Folder /tmp/plugins removed Feb 23 15:22:40 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:40.207+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:40 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:40.710+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:40 volumio4 volumio[1270]: info: Check plugin dependencies Feb 23 15:22:40 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 15:22:40 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:40.767+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:40 volumio4 volumio[1270]: info: Checking if plugin already exists Feb 23 15:22:40 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:40.774+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:40 volumio4 volumio[1270]: info: Rename folder Feb 23 15:22:40 volumio4 volumio[1270]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 15:22:40 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:40.795+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:40 volumio4 volumio[1270]: info: Move to category Feb 23 15:22:41 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:41.928+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:41 volumio4 volumio[1270]: info: Checking if install.sh is present Feb 23 15:22:41 volumio4 volumio[1270]: info: Executing install.sh Feb 23 15:22:41 volumio4 sudo[5169]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Feb 23 15:22:41 volumio4 sudo[5169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:41 volumio4 volumio[1270]: info: Installing Go-librespot Feb 23 15:22:41 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:41.972+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:41 volumio4 volumio[1270]: info: Checking old vollibrespot installs Feb 23 15:22:41 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:41.982+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:42 volumio4 systemd[1]: Reloading. Feb 23 15:22:42 volumio4 volumio[1270]: info: Downloading daemon Feb 23 15:22:42 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:42.860+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:44 volumio4 volumio[1270]: info: Creating directories Feb 23 15:22:44 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:44.728+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:44 volumio4 volumio[1270]: info: Creating data directory Feb 23 15:22:44 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:44.741+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:44 volumio4 volumio[1270]: info: Creating Start Script Feb 23 15:22:44 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:44.753+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:44 volumio4 systemd[1]: Reloading. Feb 23 15:22:45 volumio4 volumio[1270]: Plugin install end detected on script Feb 23 15:22:45 volumio4 sudo[5169]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:45 volumio4 volumio[1270]: info: Install script completed Feb 23 15:22:45 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:45.578+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:45 volumio4 volumio[1270]: info: Adding reference to registry Feb 23 15:22:45 volumio4 volumio5-onboarding[1780]: time=2026-02-23T15:22:45.588+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Feb 23 15:22:45 volumio4 volumio[1270]: info: Done installing plugin. Feb 23 15:22:45 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:22:45 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 15:22:45 volumio4 volumio[1270]: info: Folder /tmp/plugins removed Feb 23 15:22:45 volumio4 volumio[1270]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 15:22:45 volumio4 volumio[1270]: info: Folder /data/temp removed Feb 23 15:22:47 volumio4 volumio[1270]: info: Enabling plugin spop Feb 23 15:22:47 volumio4 volumio[1270]: info: Loading plugin "spop"... Feb 23 15:22:48 volumio4 volumio[1270]: info: PLUGIN START: spop Feb 23 15:22:48 volumio4 volumio[1270]: info: Creating Spotify config file Feb 23 15:22:48 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:22:48 volumio4 volumio[1270]: info: Done. Feb 23 15:22:48 volumio4 volumio[1270]: info: Spotify config file written Feb 23 15:22:48 volumio4 volumio[1270]: info: No need to fix Spotify hosts Feb 23 15:22:48 volumio4 sudo[5240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 15:22:48 volumio4 sudo[5240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:48 volumio4 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. Feb 23 15:22:48 volumio4 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. Feb 23 15:22:48 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:48 volumio4 go-librespot[5242]: go-librespot daemon starting... Feb 23 15:22:48 volumio4 sudo[5240]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=info msg="running go-librespot 0.6.2" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=debug msg="no app state found" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=debug msg="stored credentials not found" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=info msg="generated new device id: e2637b6f550b1c7a791a9da046569f70a27703fc" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 23 15:22:48 volumio4 go-librespot[5243]: time="2026-02-23T15:22:48+01:00" level=info msg="zeroconf server listening on port 34389" Feb 23 15:22:49 volumio4 volumio[1270]: info: Enabling plugin spop Feb 23 15:22:49 volumio4 volumio[1270]: info: Loading plugin "spop"... Feb 23 15:22:49 volumio4 volumio[1270]: info: PLUGIN START: spop Feb 23 15:22:49 volumio4 volumio[1270]: info: Creating Spotify config file Feb 23 15:22:49 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:22:49 volumio4 volumio[1270]: info: Done. Feb 23 15:22:49 volumio4 volumio[1270]: info: Spotify config file written Feb 23 15:22:49 volumio4 volumio[1270]: info: No need to fix Spotify hosts Feb 23 15:22:49 volumio4 sudo[5253]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 15:22:49 volumio4 sudo[5253]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:49 volumio4 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 15:22:49 volumio4 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 15:22:49 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:49 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:49 volumio4 go-librespot[5255]: go-librespot daemon starting... Feb 23 15:22:49 volumio4 sudo[5253]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=info msg="running go-librespot 0.6.2" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=debug msg="app state loaded" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=debug msg="stored credentials not found" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 23 15:22:49 volumio4 go-librespot[5256]: time="2026-02-23T15:22:49+01:00" level=info msg="zeroconf server listening on port 34189" Feb 23 15:22:51 volumio4 volumio[1270]: info: Enabling plugin spop Feb 23 15:22:51 volumio4 volumio[1270]: info: Loading plugin "spop"... Feb 23 15:22:51 volumio4 volumio[1270]: info: PLUGIN START: spop Feb 23 15:22:51 volumio4 volumio[1270]: info: Creating Spotify config file Feb 23 15:22:51 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:22:51 volumio4 volumio[1270]: info: Done. Feb 23 15:22:51 volumio4 volumio[1270]: info: No need to fix Spotify hosts Feb 23 15:22:51 volumio4 volumio[1270]: info: Spotify config file written Feb 23 15:22:51 volumio4 sudo[5279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 15:22:51 volumio4 sudo[5279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:51 volumio4 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 15:22:51 volumio4 systemd[1]: go-librespot-daemon.service: Killing process 5260 (go-librespot) with signal SIGKILL. Feb 23 15:22:51 volumio4 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 15:22:51 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:51 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:51 volumio4 go-librespot[5281]: go-librespot daemon starting... Feb 23 15:22:51 volumio4 sudo[5279]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=info msg="running go-librespot 0.6.2" Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=debug msg="app state loaded" Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=debug msg="stored credentials not found" Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 15:22:51 volumio4 volumio[1270]: info: go-librespot daemon successfully initialized Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 23 15:22:51 volumio4 go-librespot[5282]: time="2026-02-23T15:22:51+01:00" level=info msg="zeroconf server listening on port 46075" Feb 23 15:22:52 volumio4 volumio[1270]: info: go-librespot daemon successfully initialized Feb 23 15:22:54 volumio4 volumio[1270]: info: go-librespot daemon successfully initialized Feb 23 15:22:54 volumio4 volumio[1270]: info: Initializing connection to go-librespot Websocket Feb 23 15:22:54 volumio4 go-librespot[5282]: time="2026-02-23T15:22:54+01:00" level=debug msg="new websocket client" Feb 23 15:22:54 volumio4 volumio[1270]: info: Connection to go-librespot Websocket established Feb 23 15:22:54 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:22:54 volumio4 volumio[1270]: info: Received Get System Info Feb 23 15:22:54 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:22:54 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:22:54 volumio4 volumio[1270]: info: Discovery: Getting this device information Feb 23 15:22:54 volumio4 volumio[1270]: info: CoreCommandRouter::volumioGetState Feb 23 15:22:54 volumio4 volumio[1270]: info: CorePlayQueue::getTrack 0 Feb 23 15:22:54 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:22:54 volumio4 volumio[1270]: info: Enabling plugin spop Feb 23 15:22:54 volumio4 volumio[1270]: info: Loading plugin "spop"... Feb 23 15:22:54 volumio4 volumio[1270]: info: PLUGIN START: spop Feb 23 15:22:54 volumio4 volumio[1270]: info: Creating Spotify config file Feb 23 15:22:54 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:22:54 volumio4 volumio[1270]: info: Done. Feb 23 15:22:54 volumio4 volumio[1270]: info: Spotify config file written Feb 23 15:22:54 volumio4 volumio[1270]: info: No need to fix Spotify hosts Feb 23 15:22:54 volumio4 sudo[5328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 15:22:54 volumio4 sudo[5328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:55 volumio4 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 15:22:55 volumio4 systemd[1]: go-librespot-daemon.service: Killing process 5290 (n/a) with signal SIGKILL. Feb 23 15:22:55 volumio4 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 15:22:55 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:55 volumio4 volumio[1270]: info: Connection to go-librespot Websocket closed Feb 23 15:22:55 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:55 volumio4 go-librespot[5330]: go-librespot daemon starting... Feb 23 15:22:55 volumio4 sudo[5328]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=info msg="running go-librespot 0.6.2" Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=debug msg="app state loaded" Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=debug msg="stored credentials not found" Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 15:22:55 volumio4 volumio[1270]: info: Initializing connection to go-librespot Websocket Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=debug msg="new websocket client" Feb 23 15:22:55 volumio4 volumio[1270]: info: Connection to go-librespot Websocket established Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 23 15:22:55 volumio4 go-librespot[5345]: time="2026-02-23T15:22:55+01:00" level=info msg="zeroconf server listening on port 44175" Feb 23 15:22:55 volumio4 volumio[1270]: info: Enabling plugin spop Feb 23 15:22:55 volumio4 volumio[1270]: info: Loading plugin "spop"... Feb 23 15:22:55 volumio4 volumio[1270]: info: PLUGIN START: spop Feb 23 15:22:55 volumio4 volumio[1270]: info: Creating Spotify config file Feb 23 15:22:55 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:22:55 volumio4 volumio[1270]: info: Done. Feb 23 15:22:55 volumio4 volumio[1270]: info: Spotify config file written Feb 23 15:22:55 volumio4 volumio[1270]: info: No need to fix Spotify hosts Feb 23 15:22:55 volumio4 sudo[5355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 15:22:55 volumio4 sudo[5355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:55 volumio4 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 15:22:55 volumio4 systemd[1]: go-librespot-daemon.service: Killing process 5350 (go-librespot) with signal SIGKILL. Feb 23 15:22:55 volumio4 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 15:22:55 volumio4 volumio[1270]: info: Connection to go-librespot Websocket closed Feb 23 15:22:55 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:55 volumio4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:55 volumio4 go-librespot[5357]: go-librespot daemon starting... Feb 23 15:22:55 volumio4 sudo[5355]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:55 volumio4 go-librespot[5358]: time="2026-02-23T15:22:55+01:00" level=info msg="running go-librespot 0.6.2" Feb 23 15:22:55 volumio4 go-librespot[5358]: time="2026-02-23T15:22:55+01:00" level=debug msg="app state loaded" Feb 23 15:22:55 volumio4 go-librespot[5358]: time="2026-02-23T15:22:55+01:00" level=debug msg="stored credentials not found" Feb 23 15:22:55 volumio4 go-librespot[5358]: time="2026-02-23T15:22:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 15:22:56 volumio4 go-librespot[5358]: time="2026-02-23T15:22:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 23 15:22:56 volumio4 go-librespot[5358]: time="2026-02-23T15:22:56+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 23 15:22:56 volumio4 go-librespot[5358]: time="2026-02-23T15:22:56+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 23 15:22:56 volumio4 go-librespot[5358]: time="2026-02-23T15:22:56+01:00" level=info msg="zeroconf server listening on port 43033" Feb 23 15:22:56 volumio4 volumio[1270]: info: Enabling plugin spop Feb 23 15:22:56 volumio4 volumio[1270]: info: Loading plugin "spop"... Feb 23 15:22:56 volumio4 volumio[1270]: info: PLUGIN START: spop Feb 23 15:22:56 volumio4 volumio[1270]: info: Creating Spotify config file Feb 23 15:22:56 volumio4 volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:22:56 volumio4 volumio[1270]: info: Done. Feb 23 15:22:56 volumio4 volumio[1270]: info: Spotify config file written Feb 23 15:22:56 volumio4 volumio[1270]: info: No need to fix Spotify hosts Feb 23 15:22:56 volumio4 sudo[5368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 15:22:56 volumio4 sudo[5368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 15:22:56 volumio4 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 15:22:56 volumio4 systemd[1]: go-librespot-daemon.service: Killing process 5360 (go-librespot) with signal SIGKILL. Feb 23 15:22:56 volumio4 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 15:22:56 volumio4 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:56 volumio4 systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Feb 23 15:22:56 volumio4 systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Feb 23 15:22:56 volumio4 systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Feb 23 15:22:56 volumio4 sudo[5368]: pam_unix(sudo:session): session closed for user root Feb 23 15:22:56 volumio4 volumio[1270]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 23 15:22:56 volumio4 volumio[1270]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 23 15:22:56 volumio4 volumio[1270]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 23 15:22:56 volumio4 volumio[1270]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 23 15:22:56 volumio4 volumio[1270]: followed by "systemctl start go-librespot-daemon.service" again. Feb 23 15:22:56 volumio4 volumio[1270]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 23 15:22:56 volumio4 volumio[1270]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 23 15:22:56 volumio4 volumio[1270]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 23 15:22:56 volumio4 volumio[1270]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 23 15:22:56 volumio4 volumio[1270]: followed by "systemctl start go-librespot-daemon.service" again. Feb 23 15:22:57 volumio4 volumio[1270]: info: Initializing connection to go-librespot Websocket Feb 23 15:22:57 volumio4 volumio[1270]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 15:22:57 volumio4 volumio[1270]: info: Getting Spotify volume Feb 23 15:22:57 volumio4 volumio[1270]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 15:22:57 volumio4 volumio[1270]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 15:22:57 volumio4 volumio[1270]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 23 15:22:57 volumio4 volumio[1270]: errno: -111, Feb 23 15:22:57 volumio4 volumio[1270]: code: 'ECONNREFUSED', Feb 23 15:22:57 volumio4 volumio[1270]: syscall: 'connect', Feb 23 15:22:57 volumio4 volumio[1270]: address: '127.0.0.1', Feb 23 15:22:57 volumio4 volumio[1270]: port: 9879, Feb 23 15:22:57 volumio4 volumio[1270]: response: undefined Feb 23 15:22:57 volumio4 volumio[1270]: } Feb 23 15:22:57 volumio4 volumio[1270]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 15:22:58 volumio4 sudo[5386]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 15:21' Feb 23 15:22:58 volumio4 sudo[5386]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"