May 28 19:48:00 volumio-markus systemd[1]: Reloading. May 28 19:48:00 volumio-markus systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal May 28 19:48:01 volumio-markus sudo[5405]: pam_unix(sudo:session): session closed for user root May 28 19:48:01 volumio-markus volumio[4034]: info: succeeded May 28 19:48:18 volumio-markus systemd[1]: systemd-timedated.service: Deactivated successfully. May 28 19:48:42 volumio-markus volumio[4034]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/spop/volumio/bookworm/armhf May 28 19:48:45 volumio-markus volumio[4034]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/spop/volumio/bookworm/armhf May 28 19:48:45 volumio-markus volumio[4034]: info: Folder /tmp/plugins removed May 28 19:48:46 volumio-markus volumio[4034]: info: Check plugin dependencies May 28 19:48:46 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 28 19:48:46 volumio-markus volumio[4034]: info: Checking if plugin already exists May 28 19:48:46 volumio-markus volumio[4034]: info: Rename folder May 28 19:48:46 volumio-markus volumio[4034]: info: Folder /tmp/downloaded_plugin.zip removed May 28 19:48:46 volumio-markus volumio[4034]: info: Move to category May 28 19:48:47 volumio-markus volumio[4034]: info: Checking if install.sh is present May 28 19:48:47 volumio-markus volumio[4034]: info: Executing install.sh May 28 19:48:47 volumio-markus sudo[5533]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh May 28 19:48:47 volumio-markus sudo[5533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 19:48:47 volumio-markus volumio[4034]: info: Installing Go-librespot May 28 19:48:47 volumio-markus volumio[4034]: info: Checking old vollibrespot installs May 28 19:48:47 volumio-markus systemd[1]: Reloading. May 28 19:48:48 volumio-markus systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal May 28 19:48:48 volumio-markus volumio[4034]: info: Downloading daemon May 28 19:48:48 volumio-markus systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 28 19:48:48 volumio-markus dbus-daemon[660]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.69' (uid=0 pid=5561 comm="timedatectl show --property=NTPSynchronized --valu") May 28 19:48:48 volumio-markus systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 28 19:48:48 volumio-markus dbus-daemon[660]: [system] Successfully activated service 'org.freedesktop.timedate1' May 28 19:48:48 volumio-markus systemd[1]: Started systemd-timedated.service - Time & Date Service. May 28 19:48:48 volumio-markus setdatetime-helper.sh[5559]: Time is not synchronized. Attempting to sync... May 28 19:48:49 volumio-markus sudo[5570]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Wed, 28 May 2025 17:48:49 GMT#015' May 28 19:48:49 volumio-markus sudo[5570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 19:48:49 volumio-markus setdatetime-helper.sh[5571]: Wed May 28 19:48:49 CEST 2025 May 28 19:48:49 volumio-markus systemd-journald[330]: Time jumped backwards, rotating. May 28 19:48:49 volumio-markus sudo[5570]: pam_unix(sudo:session): session closed for user root May 28 19:48:49 volumio-markus setdatetime-helper.sh[5559]: Time synchronized successfully. May 28 19:48:49 volumio-markus systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 28 19:48:49 volumio-markus systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 28 19:48:51 volumio-markus volumio[4034]: info: Creating directories May 28 19:48:51 volumio-markus volumio[4034]: info: Creating data directory May 28 19:48:51 volumio-markus volumio[4034]: info: Creating Start Script May 28 19:48:51 volumio-markus systemd[1]: Reloading. May 28 19:48:51 volumio-markus systemd[1]: /etc/systemd/system/musicservicesshield.service:14: Failed to parse output specifier, ignoring: jouurnal May 28 19:48:51 volumio-markus sudo[5533]: pam_unix(sudo:session): session closed for user root May 28 19:48:51 volumio-markus volumio[4034]: Plugin install end detected on script May 28 19:48:51 volumio-markus volumio[4034]: info: Install script completed May 28 19:48:51 volumio-markus volumio[4034]: info: Adding reference to registry May 28 19:48:51 volumio-markus volumio[4034]: info: Done installing plugin. May 28 19:48:51 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 19:48:51 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 28 19:48:51 volumio-markus volumio[4034]: info: Folder /tmp/plugins removed May 28 19:48:51 volumio-markus volumio[4034]: info: Folder /tmp/downloaded_plugin.zip removed May 28 19:48:51 volumio-markus volumio[4034]: info: Folder /data/temp removed May 28 19:48:53 volumio-markus volumio[4034]: info: Enabling plugin spop May 28 19:48:53 volumio-markus volumio[4034]: info: Loading plugin "spop"... May 28 19:48:54 volumio-markus volumio[4034]: info: PLUGIN START: spop May 28 19:48:54 volumio-markus volumio[4034]: info: Creating Spotify config file May 28 19:48:54 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 19:48:54 volumio-markus volumio[4034]: info: Done. May 28 19:48:54 volumio-markus volumio[4034]: info: Spotify config file written May 28 19:48:54 volumio-markus volumio[4034]: info: No need to fix Spotify hosts May 28 19:48:54 volumio-markus sudo[5616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 28 19:48:54 volumio-markus sudo[5616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 19:48:54 volumio-markus 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. May 28 19:48:54 volumio-markus 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. May 28 19:48:54 volumio-markus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 28 19:48:54 volumio-markus sudo[5616]: pam_unix(sudo:session): session closed for user root May 28 19:48:54 volumio-markus go-librespot[5618]: go-librespot daemon starting... May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02:00" level=info msg="running go-librespot 0.2.0" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02:00" level=debug msg="no app state found" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02:00" level=debug msg="stored credentials not found" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02:00" level=info msg="generated new device id: 7427dcc93145388c76b26f142d10df5d93bc3744" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02: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]" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02: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]" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02: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]" May 28 19:48:54 volumio-markus go-librespot[5619]: time="2025-05-28T19:48:54+02:00" level=info msg="zeroconf server listening on port 37981" May 28 19:48:57 volumio-markus volumio[4034]: info: go-librespot daemon successfully initialized May 28 19:49:00 volumio-markus volumio[4034]: info: Initializing connection to go-librespot Websocket May 28 19:49:00 volumio-markus go-librespot[5619]: time="2025-05-28T19:49:00+02:00" level=debug msg="new websocket client" May 28 19:49:00 volumio-markus volumio[4034]: info: Connection to go-librespot Websocket established May 28 19:49:03 volumio-markus volumio[4034]: info: Getting Spotify volume May 28 19:49:03 volumio-markus volumio[4034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 28 19:49:03 volumio-markus volumio[4034]: info: CoreCommandRouter::volumioGetState May 28 19:49:13 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 28 19:49:15 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 28 19:49:18 volumio-markus systemd[1]: systemd-timedated.service: Deactivated successfully. May 28 19:49:28 volumio-markus volumio[4034]: info: CoreCommandRouter::volumioGetState May 28 19:49:33 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 28 19:49:33 volumio-markus volumio[4034]: info: Preload queue cleared May 28 19:49:35 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 28 19:49:35 volumio-markus volumio[4034]: info: Preload queue cleared May 28 19:49:39 volumio-markus volumio[4034]: Searching plugin music_service/webradio May 28 19:49:39 volumio-markus volumio[4034]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 28 19:49:40 volumio-markus volumio[4034]: Use XMLElement.setAttribute instead May 28 19:49:40 volumio-markus volumio[4034]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 19:49:40 volumio-markus volumio[4034]: TypeError: children[i].attr(...).value is not a function May 28 19:49:40 volumio-markus volumio[4034]: at /volumio/app/plugins/music_service/webradio/index.js:956:46 May 28 19:49:40 volumio-markus volumio[4034]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) May 28 19:49:40 volumio-markus volumio[4034]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 19:49:40 volumio-markus sudo[5715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-28 19:48' May 28 19:49:40 volumio-markus sudo[5715]: 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="1da895bfdbb6eb90d965df32a25a3568df7c84ed" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed May 28 07:32:00 UTC 2025" VOLUMIO_VERSION="4.002" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="0fc76cf16cbffb5d07df2b0e7f3ca424"