Jul 10 16:24:43 volumio ntpd[1089]: CLOCK: time stepped by 480307.327035 Jul 10 16:24:43 volumio ntpd[1089]: CLOCK: time changed from 2025-07-05 to 2025-07-10 Jul 10 16:24:43 volumio ntpd[1089]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jul 10 16:24:44 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Jul 10 16:24:44 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Jul 10 16:24:44 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Jul 10 16:24:44 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Jul 10 16:24:44 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: A device disappeared from network Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: Device volumio disappeared from network Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: A device disappeared from network Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: A device disappeared from network Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: adding 42901cc8-5d3d-409d-9147-b8b3418a2d93 Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: Found device Volumio Jul 10 16:24:44 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Jul 10 16:24:44 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: this is already registered, 42901cc8-5d3d-409d-9147-b8b3418a2d93 Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: Found device Volumio Jul 10 16:24:44 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Jul 10 16:24:44 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: this is already registered, 42901cc8-5d3d-409d-9147-b8b3418a2d93 Jul 10 16:24:44 volumio volumio[1306]: info: Discovery: Found device Volumio Jul 10 16:24:44 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Jul 10 16:24:44 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Jul 10 16:24:45 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Jul 10 16:24:48 volumio systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Jul 10 16:24:48 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Jul 10 16:24:48 volumio systemd[1]: e2scrub_all.service: Deactivated successfully. Jul 10 16:24:48 volumio systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Jul 10 16:24:57 volumio upmpdcli[1719]: writing RSA key Jul 10 16:24:58 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 10 16:24:58 volumio volumio[1306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jul 10 16:24:58 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Jul 10 16:24:58 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Jul 10 16:25:00 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Jul 10 16:25:01 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 10 16:25:01 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 16:25:01 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 10 16:25:01 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jul 10 16:25:01 volumio volumio-remote-updater[929]: Test mode disabled Jul 10 16:25:01 volumio volumio-remote-updater[929]: Alpha mode disabled Jul 10 16:25:01 volumio volumio-remote-updater[929]: Alpha legacy test mode disabled Jul 10 16:25:01 volumio volumio[1306]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jul 10 16:25:01 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::volumioGetBrowseSources Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 10 16:25:03 volumio volumio[1306]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jul 10 16:25:03 volumio volumio[1306]: info: Completed starting MyVolumio Plugin Jul 10 16:25:03 volumio volumio[1306]: [Metrics] CommandRouter: 36s 852.58ms Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::volumiosetStartupVolume Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::Close All Modals sent Jul 10 16:25:03 volumio volumio[1306]: info: CoreCommandRouter::Close All Modals sent Jul 10 16:25:03 volumio volumio[1306]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Jul 10 16:25:03 volumio volumio[1306]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for b1 Jul 10 16:25:03 volumio volumio[1306]: aplay: main:831: audio open error: No such device Jul 10 16:25:04 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 10 16:25:04 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 10 16:25:04 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 10 16:25:10 volumio volumio[1306]: info: BOOT COMPLETED Jul 10 16:25:33 volumio sudo[1798]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 10 16:25:33 volumio sudo[1796]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 10 16:25:33 volumio sudo[1798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 10 16:25:33 volumio sudo[1796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 10 16:25:33 volumio sudo[1798]: pam_unix(sudo:session): session closed for user root Jul 10 16:25:33 volumio sudo[1796]: pam_unix(sudo:session): session closed for user root Jul 10 16:25:34 volumio volumio[1306]: verbose: New Socket.io Connection to 192.168.0.46 from 192.168.0.16 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.0 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 4 Jul 10 16:25:34 volumio volumio[1306]: info: CoreCommandRouter::volumioGetVisibleSources Jul 10 16:25:34 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 10 16:25:35 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 10 16:25:36 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jul 10 16:25:36 volumio volumio[1306]: info: MyVolumio login type: Token Jul 10 16:25:36 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 10 16:25:36 volumio volumio[1306]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 10 16:25:37 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jul 10 16:25:37 volumio volumio[1306]: info: MyVolumio login type: Token Jul 10 16:25:38 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 10 16:25:39 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 10 16:25:40 volumio volumio[1306]: info: MyVolumio token set successfully Jul 10 16:25:40 volumio volumio[1306]: info: MYVOLUMIO: Adding device Jul 10 16:25:40 volumio volumio[1306]: info: MYVOLUMIO: Evaluating Server Jul 10 16:25:40 volumio volumio[1306]: info: MyVolumio status changed Jul 10 16:25:40 volumio volumio[1306]: info: Streaming services startup Jul 10 16:25:40 volumio volumio[1306]: info: Starting Streaming Daemon Jul 10 16:25:40 volumio volumio[1306]: info: Removing browser output: myVolumio user plan is not superstar Jul 10 16:25:40 volumio volumio[1306]: info: Removing audio output: Jul 10 16:25:40 volumio volumio[1306]: info: Stoppping Tunnel 1 Jul 10 16:25:40 volumio sudo[1833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 10 16:25:40 volumio sudo[1833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 10 16:25:40 volumio sudo[1835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jul 10 16:25:40 volumio sudo[1835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 10 16:25:40 volumio sudo[1833]: pam_unix(sudo:session): session closed for user root Jul 10 16:25:40 volumio volumio[1306]: error: Cannot start Volumio Streaming Daemon Jul 10 16:25:40 volumio volumio[1306]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 10 16:25:40 volumio volumio[1306]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 10 16:25:40 volumio sudo[1835]: pam_unix(sudo:session): session closed for user root Jul 10 16:25:40 volumio volumio[1306]: info: Remote SSH Stopped Jul 10 16:25:40 volumio dbus-daemon[918]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.23' (uid=0 pid=1839 comm="timedatectl show --property=NTPSynchronized --valu") Jul 10 16:25:40 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jul 10 16:25:40 volumio dbus-daemon[918]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 10 16:25:40 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jul 10 16:25:40 volumio setdatetime-helper.sh[1838]: Time is not synchronized. Attempting to sync... Jul 10 16:25:40 volumio sudo[1847]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 10 Jul 2025 16:25:40 GMT#015' Jul 10 16:25:40 volumio sudo[1847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 10 16:25:40 volumio setdatetime-helper.sh[1848]: Thu Jul 10 16:25:40 UTC 2025 Jul 10 16:25:40 volumio setdatetime-helper.sh[1838]: Time synchronized successfully. Jul 10 16:25:40 volumio sudo[1847]: pam_unix(sudo:session): session closed for user root Jul 10 16:25:40 volumio systemd-journald[421]: Time jumped backwards, rotating. Jul 10 16:25:40 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 10 16:25:40 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 10 16:25:40 volumio volumio[1306]: error: Failed to ping endpoint as1.myvolumio.org : unknown error Jul 10 16:25:40 volumio volumio[1306]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 10 16:25:40 volumio volumio[1306]: Error: Unable to resolve or reject the same promise twice Jul 10 16:25:40 volumio volumio[1306]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jul 10 16:25:40 volumio volumio[1306]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32090) Jul 10 16:25:40 volumio volumio[1306]: at Socket.emit (node:events:526:35) Jul 10 16:25:40 volumio volumio[1306]: at endReadableNT (node:internal/streams/readable:1376:12) Jul 10 16:25:40 volumio volumio[1306]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) Jul 10 16:25:40 volumio volumio[1306]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 10 16:25:40 volumio sudo[1864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-10 16:24' Jul 10 16:25:40 volumio sudo[1864]: 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="4f980d5cf693b4272997a2fa2da8bb8036ddf1ab" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jul 5 02:50:33 UTC 2025" VOLUMIO_VERSION="4.015" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d42ab79cc13d24482826e04fda2e8350"