-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Fri 2025-01-10 20:15:14 EST. -- Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77cf3f8a does not match aorg 0000000000.00000000 from server@173.255.206.154 xmt 0xeb2c4480.829af5b2 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77ccf7d4 does not match aorg 0000000000.00000000 from server@149.28.61.105 xmt 0xeb2c4480.825c9b60 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77c53dab does not match aorg 0000000000.00000000 from server@12.205.28.193 xmt 0xeb2c4480.829cd4e2 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77ca707f does not match aorg 0000000000.00000000 from server@23.150.40.242 xmt 0xeb2c4480.835df704 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77cb60f2 does not match aorg 0000000000.00000000 from server@23.150.41.122 xmt 0xeb2c4480.83c8c008 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77c99ecb does not match aorg 0000000000.00000000 from server@23.155.40.38 xmt 0xeb2c4480.831fbfe4 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77cc2560 does not match aorg 0000000000.00000000 from server@148.135.119.56 xmt 0xeb2c4480.868b2810 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77ce8101 does not match aorg 0000000000.00000000 from server@149.248.12.167 xmt 0xeb2c4480.86943f46 Jan 10 20:14:40 volumio systemd[1]: Starting Daily apt download activities... Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77d00104 does not match aorg 0000000000.00000000 from server@198.137.202.56 xmt 0xeb2c4480.87b2f219 Jan 10 20:14:40 volumio ntpd[782]: receive: Unexpected origin timestamp 0xeb26dbc9.77c8b0b7 does not match aorg 0000000000.00000000 from server@198.60.22.240 xmt 0xeb2c4480.85af96c7 Jan 10 20:14:40 volumio systemd[1]: Starting Daily man-db regeneration... Jan 10 20:14:40 volumio volumio[994]: info: Discovery: A device disappeared from network Jan 10 20:14:40 volumio volumio[994]: info: Discovery: Device volumio disappeared from network Jan 10 20:14:41 volumio ntpd[782]: Soliciting pool server 2604:2dc0:101:200::151 Jan 10 20:14:41 volumio systemd[1]: man-db.service: Succeeded. Jan 10 20:14:41 volumio systemd[1]: Started Daily man-db regeneration. Jan 10 20:14:42 volumio systemd[1]: apt-daily.service: Succeeded. Jan 10 20:14:42 volumio systemd[1]: Started Daily apt download activities. Jan 10 20:14:42 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jan 10 20:14:43 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jan 10 20:14:43 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jan 10 20:14:43 volumio volumio[994]: error: MyVolumio Custom Token format not valid, refreshing it Jan 10 20:14:45 volumio volumio[994]: info: MyVolumio login type: Token Jan 10 20:14:49 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 10 20:14:50 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 10 20:14:50 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 10 20:14:50 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::volumioGetBrowseSources Jan 10 20:14:54 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 10 20:14:55 volumio volumio[994]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 10 20:14:59 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 20:14:59 volumio volumio[994]: info: Received Get System Info Jan 10 20:14:59 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 20:14:59 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 20:14:59 volumio volumio[994]: info: Discovery: Getting this device information Jan 10 20:14:59 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 10 20:14:59 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 10 20:14:59 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 20:14:59 volumio volumio[994]: info: Discovery: adding f42f7523-8556-446e-b8a8-80a5e6aa4e26 Jan 10 20:14:59 volumio volumio[994]: info: Discovery: Found device Volumio Jan 10 20:14:59 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 10 20:14:59 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 10 20:15:00 volumio volumio[994]: info: MyVolumio token set successfully Jan 10 20:15:00 volumio volumio[994]: info: MYVOLUMIO: Adding device Jan 10 20:15:00 volumio volumio[994]: info: MYVOLUMIO: Evaluating Server Jan 10 20:15:00 volumio volumio[994]: info: MyVolumio Plan changed: premium Jan 10 20:15:00 volumio volumio[994]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Jan 10 20:15:00 volumio volumio[994]: info: Removing browser output: myVolumio user plan is not superstar Jan 10 20:15:00 volumio volumio[994]: info: Removing audio output: Jan 10 20:15:00 volumio volumio[994]: info: MYVOLUMIO: Adding device Jan 10 20:15:00 volumio volumio[994]: info: MYVOLUMIO: Evaluating Server Jan 10 20:15:00 volumio volumio[994]: info: Remote config written successfully Jan 10 20:15:00 volumio volumio[994]: info: Starting Tunnel 1 Jan 10 20:15:00 volumio volumio[994]: info: Starting Tunnel Connection Checker Jan 10 20:15:00 volumio volumio[994]: info: MYVolumio Device enabled Jan 10 20:15:00 volumio volumio[994]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jan 10 20:15:00 volumio volumio[994]: info: MyVolumio status changed Jan 10 20:15:00 volumio volumio[994]: info: Streaming services startup Jan 10 20:15:00 volumio volumio[994]: info: Starting Streaming Daemon Jan 10 20:15:00 volumio sudo[2668]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 10 20:15:00 volumio sudo[2668]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 10 20:15:00 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jan 10 20:15:00 volumio volumio[994]: error: [MyVolumio PluginManager] Cache data is invalid! Jan 10 20:15:00 volumio sudo[2668]: pam_unix(sudo:session): session closed for user root Jan 10 20:15:01 volumio volumio[994]: error: Cannot start Volumio Streaming Daemon Jan 10 20:15:01 volumio volumio[994]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 10 20:15:01 volumio volumio[994]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 10 20:15:01 volumio volumio-time-update[602]: volumio-time-update-util: Date not found in response Jan 10 20:15:01 volumio volumio-time-update[602]: volumio-time-update-util: Retrying in 5 seconds... Jan 10 20:15:05 volumio sudo[2681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jan 10 20:15:05 volumio sudo[2681]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 10 20:15:05 volumio systemd[1]: Started MyVolumio SSH Tunnel. Jan 10 20:15:05 volumio sudo[2681]: pam_unix(sudo:session): session closed for user root Jan 10 20:15:05 volumio volumio[994]: info: Remote SSH Started Jan 10 20:15:05 volumio autossh[2684]: port set to 0, monitoring disabled Jan 10 20:15:05 volumio autossh[2684]: starting ssh (count 1) Jan 10 20:15:05 volumio autossh[2684]: ssh child pid is 2687 Jan 10 20:15:06 volumio volumio-time-update[602]: volumio-time-update-util: Fetching time from Volumio... Jan 10 20:15:13 volumio volumio[994]: info: Setting Geolocation for MyVolumio to us1 Jan 10 20:15:13 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 10 20:15:13 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 10 20:15:13 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 10 20:15:14 volumio volumio[994]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 10 20:15:14 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 10 20:15:14 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 10 20:15:14 volumio volumiossh-tunnel[2683]: Warning: Permanently added '[eu1.myvolumio.org]:2222,[68.183.69.189]:2222' (RSA) to the list of known hosts. Jan 10 20:15:14 volumio volumio[994]: info: Successfully Added MyVolumio device Jan 10 20:15:14 volumio volumio-time-update[602]: volumio-time-update-util: Setting system time to: 2025-01-10 20:15:14 Jan 10 20:15:14 volumio sudo[2753]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-01-10 20:15:14 Jan 10 20:15:14 volumio sudo[2753]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 10 20:15:14 volumio dbus-daemon[613]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.20' (uid=0 pid=2754 comm="timedatectl set-time 2025-01-10 20:15:14 ") Jan 10 20:15:14 volumio volumio[994]: info: Updating MyVolumio device info Jan 10 20:15:14 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 10 20:15:14 volumio systemd[1]: Starting Time & Date Service... Jan 10 20:15:14 volumio dbus-daemon[613]: [system] Successfully activated service 'org.freedesktop.timedate1' Jan 10 20:15:14 volumio systemd[1]: Started Time & Date Service. Jan 10 20:15:14 volumio systemd-timedated[2755]: Changed local time to Fri Jan 10 20:15:14 2025 Jan 10 20:15:14 volumio sudo[2753]: pam_unix(sudo:session): session closed for user root Jan 10 20:15:14 volumio volumio[994]: error: Failed to ping endpoint us3.myvolumio.org : unknown error Jan 10 20:15:14 volumio volumio-time-update[602]: volumio-time-update-util: System time updated successfully. Jan 10 20:15:14 volumio volumio[994]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 20:15:14 volumio systemd[1]: Started Volumio Time Update Utility. Jan 10 20:15:14 volumio systemd[1]: Reached target Multi-User System. Jan 10 20:15:14 volumio systemd[1]: Reached target Graphical Interface. Jan 10 20:15:14 volumio volumio[994]: Error: Unable to resolve or reject the same promise twice Jan 10 20:15:14 volumio volumio[994]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jan 10 20:15:14 volumio volumio[994]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Jan 10 20:15:14 volumio volumio[994]: at Socket.emit (events.js:327:22) Jan 10 20:15:14 volumio volumio[994]: at endReadableNT (internal/streams/readable.js:1327:12) Jan 10 20:15:14 volumio volumio[994]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jan 10 20:15:14 volumio volumio[994]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 20:15:14 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 10 20:15:14 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 10 20:15:14 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 10 20:15:14 volumio systemd[1]: Startup finished in 11.871s (kernel) + 5min 11.052s (userspace) = 5min 22.924s. Jan 10 20:15:14 volumio sudo[2768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-10 20:14 Jan 10 20:15:14 volumio sudo[2768]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"