May 20 18:14:17 volumio-higole-x86 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 20 18:14:17 volumio-higole-x86 dbus-daemon[871]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.45' (uid=0 pid=3286 comm="timedatectl show --property=NTPSynchronized --valu") May 20 18:14:17 volumio-higole-x86 systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 20 18:14:17 volumio-higole-x86 dbus-daemon[871]: [system] Successfully activated service 'org.freedesktop.timedate1' May 20 18:14:17 volumio-higole-x86 systemd[1]: Started systemd-timedated.service - Time & Date Service. May 20 18:14:17 volumio-higole-x86 setdatetime-helper.sh[3285]: Time is not synchronized. Attempting to sync... May 20 18:14:17 volumio-higole-x86 sudo[3294]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Tue, 20 May 2025 16:14:17 GMT#015' May 20 18:14:17 volumio-higole-x86 sudo[3294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 20 18:14:17 volumio-higole-x86 setdatetime-helper.sh[3295]: Tue May 20 18:14:17 CEST 2025 May 20 18:14:17 volumio-higole-x86 sudo[3294]: pam_unix(sudo:session): session closed for user root May 20 18:14:17 volumio-higole-x86 systemd-journald[497]: Time jumped backwards, rotating. May 20 18:14:17 volumio-higole-x86 setdatetime-helper.sh[3285]: Time synchronized successfully. May 20 18:14:17 volumio-higole-x86 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 20 18:14:17 volumio-higole-x86 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 20 18:14:21 volumio-higole-x86 systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... May 20 18:14:21 volumio-higole-x86 systemd[1]: apt-daily-upgrade.service: Deactivated successfully. May 20 18:14:21 volumio-higole-x86 systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. May 20 18:14:46 volumio-higole-x86 systemd[1]: systemd-timedated.service: Deactivated successfully. May 20 18:15:44 volumio-higole-x86 sudo[3496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 20 18:15:44 volumio-higole-x86 sudo[3496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 20 18:15:44 volumio-higole-x86 sudo[3498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 20 18:15:44 volumio-higole-x86 sudo[3498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 20 18:15:44 volumio-higole-x86 sudo[3496]: pam_unix(sudo:session): session closed for user root May 20 18:15:44 volumio-higole-x86 sudo[3498]: pam_unix(sudo:session): session closed for user root May 20 18:15:44 volumio-higole-x86 volumio[1149]: verbose: New Socket.io Connection to 192.168.1.92 from 192.168.1.50 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:138.0) Gecko/20100101 Firefox/138.0 Engine version: 3 Transport: polling Total Clients: 7 May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetVisibleSources May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetState May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CorePlayQueue::getTrack 0 May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: Received Get System Info May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: Discovery: Getting this device information May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetState May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CorePlayQueue::getTrack 0 May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetState May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CorePlayQueue::getTrack 0 May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: Listing playlists May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 20 18:15:44 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 20 18:15:45 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetState May 20 18:15:45 volumio-higole-x86 volumio[1149]: info: CorePlayQueue::getTrack 0 May 20 18:15:45 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: Received Get System Info May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: Discovery: Getting this device information May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetState May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CorePlayQueue::getTrack 0 May 20 18:15:46 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 20 18:15:48 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 20 18:15:48 volumio-higole-x86 volumio[1149]: info: MyVolumio login type: Token May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: Received Get System Info May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: Discovery: Getting this device information May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::volumioGetState May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: CorePlayQueue::getTrack 0 May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: MyVolumio token set successfully May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: MYVOLUMIO: Adding device May 20 18:15:49 volumio-higole-x86 volumio[1149]: info: MYVOLUMIO: Evaluating Server May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: MyVolumio Plan changed: superstar May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: [MyVolumio PluginManager] Subscribed plan changed to superstar May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: Adding audio output: May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: MYVOLUMIO: Adding device May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: MYVOLUMIO: Evaluating Server May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: Remote config written successfully May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: Starting Tunnel 1 May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: Starting Tunnel Connection Checker May 20 18:15:50 volumio-higole-x86 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 20 18:15:50 volumio-higole-x86 dbus-daemon[871]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.47' (uid=0 pid=3534 comm="timedatectl show --property=NTPSynchronized --valu") May 20 18:15:50 volumio-higole-x86 systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 20 18:15:50 volumio-higole-x86 dbus-daemon[871]: [system] Successfully activated service 'org.freedesktop.timedate1' May 20 18:15:50 volumio-higole-x86 systemd[1]: Started systemd-timedated.service - Time & Date Service. May 20 18:15:50 volumio-higole-x86 setdatetime-helper.sh[3533]: Time is not synchronized. Attempting to sync... May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: MYVolumio Device enabled May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: MyVolumio status changed May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: Streaming services startup May 20 18:15:50 volumio-higole-x86 volumio[1149]: info: Starting Streaming Daemon May 20 18:15:50 volumio-higole-x86 volumio[1149]: error: [MyVolumio PluginManager] Could not read cache file: ENOENT: no such file or directory, open '/data/myvolumio/cache.data' May 20 18:15:50 volumio-higole-x86 sudo[3558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 20 18:15:50 volumio-higole-x86 sudo[3558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 20 18:15:50 volumio-higole-x86 sudo[3558]: pam_unix(sudo:session): session closed for user root May 20 18:15:50 volumio-higole-x86 volumio[1149]: error: Cannot start Volumio Streaming Daemon May 20 18:15:50 volumio-higole-x86 volumio[1149]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 20 18:15:50 volumio-higole-x86 volumio[1149]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 20 18:15:50 volumio-higole-x86 sudo[3560]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Tue, 20 May 2025 16:15:50 GMT#015' May 20 18:15:50 volumio-higole-x86 sudo[3560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 20 18:15:50 volumio-higole-x86 setdatetime-helper.sh[3561]: Tue May 20 18:15:50 CEST 2025 May 20 18:15:50 volumio-higole-x86 setdatetime-helper.sh[3533]: Time synchronized successfully. May 20 18:15:50 volumio-higole-x86 sudo[3560]: pam_unix(sudo:session): session closed for user root May 20 18:15:50 volumio-higole-x86 volumio[1149]: error: Failed to ping endpoint eu7.myvolumio.org : unknown error May 20 18:15:50 volumio-higole-x86 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 20 18:15:50 volumio-higole-x86 volumio[1149]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 20 18:15:50 volumio-higole-x86 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 20 18:15:50 volumio-higole-x86 systemd-journald[497]: Time jumped backwards, rotating. May 20 18:15:50 volumio-higole-x86 volumio[1149]: Error: Unable to resolve or reject the same promise twice May 20 18:15:50 volumio-higole-x86 volumio[1149]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 20 18:15:50 volumio-higole-x86 volumio[1149]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32371) May 20 18:15:50 volumio-higole-x86 volumio[1149]: at Socket.emit (node:events:514:28) May 20 18:15:50 volumio-higole-x86 volumio[1149]: at addChunk (node:internal/streams/readable:343:12) May 20 18:15:50 volumio-higole-x86 volumio[1149]: at readableAddChunk (node:internal/streams/readable:316:9) May 20 18:15:50 volumio-higole-x86 volumio[1149]: at Readable.push (node:internal/streams/readable:253:10) May 20 18:15:50 volumio-higole-x86 volumio[1149]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) May 20 18:15:50 volumio-higole-x86 volumio[1149]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 20 18:15:50 volumio-higole-x86 sudo[3578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-20 18:14' May 20 18:15:50 volumio-higole-x86 sudo[3578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="f224c96f24bffeaafa716653a140d091b9b76522" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon May 19 11:05:09 UTC 2025" VOLUMIO_VERSION="0.067" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="37e5aed7881b3d72147ad6ac2a0a4d19"