-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-12-11 14:18:52 CET. -- Dec 11 14:18:48 volumio ntpd[827]: receive: Unexpected origin timestamp 0xecdf7ae8.a623fbea does not match aorg 0000000000.00000000 from server@195.32.70.195 xmt 0xece54338.f16f21f6 Dec 11 14:18:48 volumio ntpd[827]: receive: Unexpected origin timestamp 0xecdf7ae8.a61e858c does not match aorg 0000000000.00000000 from server@89.46.74.148 xmt 0xece54338.f17912a3 Dec 11 14:18:49 volumio volumio[1018]: info: Initializing connection to go-librespot Websocket Dec 11 14:18:49 volumio volumio[1018]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 11 14:18:48 volumio ntpd[827]: receive: Unexpected origin timestamp 0xecdf7ae8.a6224405 does not match aorg 0000000000.00000000 from server@93.94.88.51 xmt 0xece54338.f3279531 Dec 11 14:18:49 volumio systemd[1]: Starting Daily apt download activities... Dec 11 14:18:49 volumio volumio[1018]: error: MyVolumio Custom Token format not valid, refreshing it Dec 11 14:18:49 volumio volumio[1018]: STREAMING PROXY: Starting server on port 3245 Dec 11 14:18:49 volumio volumio[1018]: Node JS runtime: 14 Dec 11 14:18:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 11 14:18:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Dec 11 14:18:49 volumio systemd[1]: Stopped go-librespot Daemon. Dec 11 14:18:49 volumio systemd[1]: Started go-librespot Daemon. Dec 11 14:18:49 volumio go-librespot[2112]: go-librespot daemon starting... Dec 11 14:18:49 volumio go-librespot[2112]: time="2025-12-11T14:18:49+01:00" level=info msg="running go-librespot 0.4.0" Dec 11 14:18:49 volumio go-librespot[2112]: time="2025-12-11T14:18:49+01:00" level=debug msg="app state loaded" Dec 11 14:18:49 volumio go-librespot[2112]: time="2025-12-11T14:18:49+01:00" level=debug msg="stored credentials not found" Dec 11 14:18:49 volumio go-librespot[2112]: time="2025-12-11T14:18:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 11 14:18:50 volumio go-librespot[2112]: time="2025-12-11T14:18:50+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]" Dec 11 14:18:50 volumio go-librespot[2112]: time="2025-12-11T14:18:50+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]" Dec 11 14:18:50 volumio go-librespot[2112]: time="2025-12-11T14:18:50+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]" Dec 11 14:18:50 volumio go-librespot[2112]: time="2025-12-11T14:18:50+01:00" level=info msg="zeroconf server listening on port 37217" Dec 11 14:18:50 volumio volumio[1018]: info: Discovery: A device disappeared from network Dec 11 14:18:50 volumio volumio[1018]: info: Discovery: Device volumio disappeared from network Dec 11 14:18:50 volumio volumio[1018]: info: Discovery: adding 2496c7ab-3c46-489a-be47-e62976043257 Dec 11 14:18:50 volumio volumio[1018]: info: Discovery: Found device Volumio Dec 11 14:18:50 volumio volumio[1018]: info: CoreCommandRouter::volumioGetState Dec 11 14:18:50 volumio volumio[1018]: info: CorePlayQueue::getTrack 0 Dec 11 14:18:50 volumio volumio[1018]: info: MyVolumio login type: Token Dec 11 14:18:50 volumio systemd[1]: apt-daily.service: Succeeded. Dec 11 14:18:50 volumio systemd[1]: Started Daily apt download activities. Dec 11 14:18:51 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Dec 11 14:18:51 volumio volumio[1018]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 11 14:18:51 volumio volumio[1018]: info: MyVolumio token set successfully Dec 11 14:18:51 volumio volumio[1018]: info: MYVOLUMIO: Adding device Dec 11 14:18:51 volumio volumio[1018]: info: MYVOLUMIO: Evaluating Server Dec 11 14:18:51 volumio volumio-time-update[633]: volumio-time-update-util: Fetching time from Volumio... Dec 11 14:18:52 volumio volumio-time-update[633]: volumio-time-update-util: Setting system time to: 2025-12-11 14:18:52 Dec 11 14:18:52 volumio volumio[1018]: info: Initializing connection to go-librespot Websocket Dec 11 14:18:52 volumio sudo[2235]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-12-11 14:18:52 Dec 11 14:18:52 volumio sudo[2235]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 11 14:18:52 volumio volumio[1018]: info: MyVolumio status changed Dec 11 14:18:52 volumio volumio[1018]: info: Streaming services startup Dec 11 14:18:52 volumio volumio[1018]: info: Starting Streaming Daemon Dec 11 14:18:52 volumio volumio[1018]: info: Removing browser output: myVolumio user plan is not superstar Dec 11 14:18:52 volumio volumio[1018]: info: Removing audio output: Dec 11 14:18:52 volumio volumio[1018]: info: Stoppping Tunnel 1 Dec 11 14:18:52 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Dec 11 14:18:52 volumio systemd[1]: Started Daily apt upgrade and clean activities. Dec 11 14:18:52 volumio dbus-daemon[643]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.16' (uid=0 pid=2238 comm="timedatectl set-time 2025-12-11 14:18:52 ") Dec 11 14:18:52 volumio sudo[2242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 11 14:18:52 volumio sudo[2242]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 11 14:18:52 volumio sudo[2244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 11 14:18:52 volumio go-librespot[2112]: time="2025-12-11T14:18:52+01:00" level=debug msg="new websocket client" Dec 11 14:18:52 volumio volumio[1018]: info: Connection to go-librespot Websocket established Dec 11 14:18:52 volumio sudo[2244]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 11 14:18:52 volumio systemd[1]: Starting Time & Date Service... Dec 11 14:18:52 volumio sudo[2242]: pam_unix(sudo:session): session closed for user root Dec 11 14:18:52 volumio volumio[1018]: error: Cannot start Volumio Streaming Daemon Dec 11 14:18:52 volumio volumio[1018]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 11 14:18:52 volumio volumio[1018]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 11 14:18:52 volumio sudo[2244]: pam_unix(sudo:session): session closed for user root Dec 11 14:18:52 volumio volumio[1018]: info: Remote SSH Stopped Dec 11 14:18:52 volumio dbus-daemon[643]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 11 14:18:52 volumio systemd[1]: Started Time & Date Service. Dec 11 14:18:52 volumio systemd-timedated[2246]: Changed local time to Thu Dec 11 14:18:52 2025 Dec 11 14:18:52 volumio sudo[2235]: pam_unix(sudo:session): session closed for user root Dec 11 14:18:52 volumio volumio-time-update[633]: volumio-time-update-util: System time updated successfully. Dec 11 14:18:52 volumio systemd[1]: Started Volumio Time Update Utility. Dec 11 14:18:52 volumio systemd[1]: Reached target Multi-User System. Dec 11 14:18:52 volumio systemd[1]: Reached target Graphical Interface. Dec 11 14:18:52 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 11 14:18:52 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 11 14:18:52 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 11 14:18:52 volumio systemd[1]: Startup finished in 12.058s (kernel) + 2min 56.010s (userspace) = 3min 8.068s. Dec 11 14:18:52 volumio volumio[1018]: error: Failed to ping endpoint au1.myvolumio.org : unknown error Dec 11 14:18:52 volumio volumio[1018]: info: Setting Geolocation for MyVolumio to eu6 Dec 11 14:18:52 volumio volumio[1018]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 14:18:52 volumio volumio[1018]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 14:18:52 volumio volumio[1018]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 11 14:18:52 volumio volumio[1018]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 11 14:18:52 volumio volumio[1018]: Error: Unable to resolve or reject the same promise twice Dec 11 14:18:52 volumio volumio[1018]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Dec 11 14:18:52 volumio volumio[1018]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Dec 11 14:18:52 volumio volumio[1018]: at Socket.emit (events.js:327:22) Dec 11 14:18:52 volumio volumio[1018]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 11 14:18:52 volumio volumio[1018]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 11 14:18:52 volumio volumio[1018]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 11 14:18:52 volumio wpa_supplicant[921]: RRM: Ignoring radio measurement request: Not RRM network Dec 11 14:18:52 volumio sudo[2259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-11 14:17 Dec 11 14:18:52 volumio sudo[2259]: 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="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"