-- Logs begin at Sun 2025-04-13 09:05:55 UTC, end at Sun 2025-04-13 09:07:41 UTC. -- Apr 13 09:06:00 volumio volumio[847]: error: MPD error: The expression evaluated to a falsy value: Apr 13 09:06:00 volumio volumio[847]: assert.ok(self.idling) Apr 13 09:06:00 volumio volumio[847]: error: The expression evaluated to a falsy value: Apr 13 09:06:00 volumio volumio[847]: assert.ok(self.idling) Apr 13 09:06:00 volumio volumio[847]: error: MPD error: The expression evaluated to a falsy value: Apr 13 09:06:00 volumio volumio[847]: assert.ok(self.idling) Apr 13 09:06:00 volumio volumio[847]: error: The expression evaluated to a falsy value: Apr 13 09:06:00 volumio volumio[847]: assert.ok(self.idling) Apr 13 09:06:00 volumio volumio[847]: error: updateQueue error: null Apr 13 09:06:00 volumio bluetoothd[1495]: Bluetooth daemon 5.50 Apr 13 09:06:00 volumio bluetoothd[1495]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Apr 13 09:06:00 volumio kernel: Bluetooth: Core ver 2.22 Apr 13 09:06:00 volumio kernel: NET: Registered PF_BLUETOOTH protocol family Apr 13 09:06:00 volumio kernel: Bluetooth: HCI device and connection manager initialized Apr 13 09:06:00 volumio kernel: Bluetooth: HCI socket layer initialized Apr 13 09:06:00 volumio kernel: Bluetooth: L2CAP socket layer initialized Apr 13 09:06:00 volumio kernel: Bluetooth: SCO socket layer initialized Apr 13 09:06:00 volumio dbus-daemon[710]: [system] Successfully activated service 'org.bluez' Apr 13 09:06:00 volumio systemd[1]: Started Bluetooth service. Apr 13 09:06:00 volumio bluetoothd[1495]: Starting SDP server Apr 13 09:06:00 volumio bluetoothd[1495]: Excluding (cli) sap Apr 13 09:06:00 volumio kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Apr 13 09:06:00 volumio kernel: Bluetooth: BNEP filters: protocol multicast Apr 13 09:06:00 volumio kernel: Bluetooth: BNEP socket layer initialized Apr 13 09:06:00 volumio dbus-daemon[710]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.10' (uid=0 pid=1495 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Apr 13 09:06:00 volumio bluetoothd[1495]: Bluetooth management interface 1.22 initialized Apr 13 09:06:00 volumio systemd[1]: Starting Hostname Service... Apr 13 09:06:00 volumio ntpd[1144]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 13 09:06:00 volumio dbus-daemon[710]: [system] Successfully activated service 'org.freedesktop.hostname1' Apr 13 09:06:00 volumio systemd[1]: Started Hostname Service. Apr 13 09:06:00 volumio volumio[847]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 13 09:06:01 volumio volumio[847]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::volumioGetVisibleSources Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Apr 13 09:06:01 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 13 09:06:01 volumio volumio[847]: info: Received Get System Info Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 09:06:01 volumio volumio[847]: info: Discovery: Getting this device information Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Apr 13 09:06:01 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Apr 13 09:06:01 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Apr 13 09:06:01 volumio volumio[847]: info: Listing playlists Apr 13 09:06:01 volumio ntpd[1144]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 13 09:06:01 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 13 09:06:01 volumio volumio-remote-updater[700]: [2025-04-13 09:06:01] [connect] Successful connection Apr 13 09:06:01 volumio volumio-remote-updater[700]: [2025-04-13 09:06:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744535161 101 Apr 13 09:06:01 volumio volumio[847]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Apr 13 09:06:01 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:01 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:01 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:02 volumio systemd[1]: systemd-rfkill.service: Succeeded. Apr 13 09:06:02 volumio sudo[1304]: pam_unix(sudo:session): session closed for user root Apr 13 09:06:02 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 13 09:06:03 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 09:06:03 volumio volumio[847]: info: Received Get System Info Apr 13 09:06:03 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 09:06:03 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 09:06:03 volumio volumio[847]: info: Discovery: Getting this device information Apr 13 09:06:03 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Apr 13 09:06:03 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Apr 13 09:06:03 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 09:06:06 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:06 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:06 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:08 volumio sudo[1811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 09:06:08 volumio sudo[1811]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:06:08 volumio sudo[1811]: pam_unix(sudo:session): session closed for user root Apr 13 09:06:08 volumio sudo[1813]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 09:06:08 volumio sudo[1813]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:06:08 volumio sudo[1813]: pam_unix(sudo:session): session closed for user root Apr 13 09:06:08 volumio sudo[1817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 13 09:06:08 volumio sudo[1817]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:06:08 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 13 09:06:08 volumio sudo[1817]: pam_unix(sudo:session): session closed for user root Apr 13 09:06:08 volumio volumio[847]: info: Upmpdcli Daemon Started Apr 13 09:06:09 volumio volumio[847]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.795&uuid=5fa7243566986c73ff88ba3df49251a6" http://updates.volumio.org/downloader-v1/track-device Apr 13 09:06:09 volumio volumio[847]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 13 09:06:09 volumio volumio[847]: Dload Upload Total Spent Left Speed Apr 13 09:06:09 volumio volumio[847]: [132B blob data] Apr 13 09:06:09 volumio volumio[847]: retrying in 5 seconds, trial 0 Apr 13 09:06:09 volumio volumio[847]: info: Volumio Calling Home Apr 13 09:06:11 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 13 09:06:11 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:11 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:11 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:16 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:16 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:16 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:19 volumio volumio[847]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.795&uuid=5fa7243566986c73ff88ba3df49251a6" http://updates.volumio.org/downloader-v1/track-device Apr 13 09:06:19 volumio volumio[847]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 13 09:06:19 volumio volumio[847]: Dload Upload Total Spent Left Speed Apr 13 09:06:19 volumio volumio[847]: [132B blob data] Apr 13 09:06:19 volumio volumio[847]: retrying in 5 seconds, trial 1 Apr 13 09:06:19 volumio volumio[847]: info: Volumio Calling Home Apr 13 09:06:19 volumio volumio[847]: error: MyVolumio Plugin failed to start in a timely fashion Apr 13 09:06:19 volumio volumio[847]: [Metrics] CommandRouter: 22s 441.68ms Apr 13 09:06:19 volumio volumio[847]: info: CoreCommandRouter::volumiosetStartupVolume Apr 13 09:06:19 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 09:06:19 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:06:19 volumio volumio[847]: info: CoreCommandRouter::Close All Modals sent Apr 13 09:06:19 volumio volumio[847]: info: CoreCommandRouter::Close All Modals sent Apr 13 09:06:20 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 13 09:06:20 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 09:06:21 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 13 09:06:21 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:21 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:21 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:26 volumio systemd[1]: systemd-fsckd.service: Succeeded. Apr 13 09:06:26 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:26 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:26 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:26 volumio volumio[847]: info: BOOT COMPLETED Apr 13 09:06:29 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 09:06:29 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:06:29 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 13 09:06:29 volumio volumio[847]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.795&uuid=5fa7243566986c73ff88ba3df49251a6" http://updates.volumio.org/downloader-v1/track-device Apr 13 09:06:29 volumio volumio[847]: % Total % Received % Xferd Average Speed Time Time Time Current Apr 13 09:06:29 volumio volumio[847]: Dload Upload Total Spent Left Speed Apr 13 09:06:29 volumio volumio[847]: [132B blob data] Apr 13 09:06:29 volumio volumio[847]: retrying in 5 seconds, trial 2 Apr 13 09:06:29 volumio volumio[847]: info: Volumio Calling Home Apr 13 09:06:30 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Apr 13 09:06:31 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:31 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:31 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:36 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:36 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:36 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:41 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:41 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:41 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:46 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:46 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:46 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:51 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:51 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:51 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:06:56 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:06:56 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:06:56 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:01 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:01 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:07:01 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:02 volumio ntpd[1144]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 13 09:07:04 volumio ntpd[1144]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 13 09:07:05 volumio ntpd[1144]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 13 09:07:06 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:06 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:07:06 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:07 volumio ntpd[1144]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 13 09:07:08 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 13 09:07:08 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 13 09:07:09 volumio kernel: e1000e 0000:00:1f.6 eth0: NIC Link is Up 1000 Mbps Half Duplex, Flow Control: Rx/Tx Apr 13 09:07:09 volumio dhcpcd[781]: eth0: carrier acquired Apr 13 09:07:09 volumio dhcpcd[781]: eth0: IAID db:0b:80:63 Apr 13 09:07:09 volumio dhcpcd[781]: eth0: adding address fe80::fe3f:dbff:fe0b:8063 Apr 13 09:07:09 volumio dhcpcd[781]: ipv6_addaddr1: Permission denied Apr 13 09:07:09 volumio kernel: e1000e 0000:00:1f.6 eth0: NIC Link is Down Apr 13 09:07:09 volumio dhcpcd[781]: eth0: soliciting an IPv6 router Apr 13 09:07:10 volumio dhcpcd[781]: eth0: soliciting a DHCP lease Apr 13 09:07:10 volumio dhcpcd[781]: eth0: carrier lost Apr 13 09:07:11 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:11 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:07:11 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:12 volumio dhcpcd[781]: eth0: carrier acquired Apr 13 09:07:12 volumio kernel: e1000e 0000:00:1f.6 eth0: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None Apr 13 09:07:12 volumio dhcpcd[781]: eth0: IAID db:0b:80:63 Apr 13 09:07:13 volumio dhcpcd[781]: eth0: soliciting a DHCP lease Apr 13 09:07:13 volumio dhcpcd[781]: eth0: soliciting an IPv6 router Apr 13 09:07:13 volumio ifplugd(eth0)[1142]: Link beat detected. Apr 13 09:07:13 volumio ifplugd(eth0)[1142]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 13 09:07:13 volumio ifplugd(eth0)[1142]: client: ifup: interface eth0 already configured Apr 13 09:07:13 volumio ifplugd(eth0)[1142]: Program executed successfully. Apr 13 09:07:16 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:16 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:07:16 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:18 volumio dhcpcd[781]: eth0: probing for an IPv4LL address Apr 13 09:07:21 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:21 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:07:21 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:23 volumio dhcpcd[781]: eth0: using IPv4LL address 169.254.71.185 Apr 13 09:07:23 volumio dhcpcd[781]: eth0: adding route to 169.254.0.0/16 Apr 13 09:07:23 volumio dhcpcd[781]: eth0: adding default route Apr 13 09:07:23 volumio avahi-daemon[704]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.71.185. Apr 13 09:07:23 volumio avahi-daemon[704]: New relevant interface eth0.IPv4 for mDNS. Apr 13 09:07:23 volumio avahi-daemon[704]: Registering new address record for 169.254.71.185 on eth0.IPv4. Apr 13 09:07:25 volumio ntpd[1144]: Listen normally on 3 eth0 169.254.71.185:123 Apr 13 09:07:25 volumio ntpd[1144]: new interface(s) found: waking up resolver Apr 13 09:07:25 volumio dhcpcd[781]: eth0: offered 192.168.1.74 from 192.168.1.254 Apr 13 09:07:26 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:27 volumio systemd[1]: nmbd.service: Start operation timed out. Terminating. Apr 13 09:07:27 volumio systemd[1]: nmbd.service: Main process exited, code=killed, status=15/TERM Apr 13 09:07:27 volumio systemd[1]: nmbd.service: Failed with result 'timeout'. Apr 13 09:07:27 volumio systemd[1]: Failed to start Samba NMB Daemon. Apr 13 09:07:27 volumio systemd[1]: Starting Samba Winbind Daemon... Apr 13 09:07:27 volumio winbindd[2101]: [2025/04/13 09:07:27.358543, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 13 09:07:27 volumio winbindd[2101]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 13 09:07:27 volumio winbindd[2101]: [2025/04/13 09:07:27.359760, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 13 09:07:27 volumio winbindd[2101]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 13 09:07:27 volumio systemd[1]: Started Samba Winbind Daemon. Apr 13 09:07:27 volumio systemd[1]: Starting Samba SMB Daemon... Apr 13 09:07:27 volumio dhcpcd[781]: eth0: probing address 192.168.1.74/24 Apr 13 09:07:27 volumio smbd[2105]: [2025/04/13 09:07:27.477880, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 13 09:07:27 volumio systemd[1]: Started Samba SMB Daemon. Apr 13 09:07:27 volumio smbd[2105]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 13 09:07:28 volumio volumio[847]: info: Volumio Network Manager: Network status updated: 1 Apr 13 09:07:32 volumio dhcpcd[781]: eth0: leased 192.168.1.74 for 43200 seconds Apr 13 09:07:32 volumio dhcpcd[781]: eth0: adding route to 192.168.1.0/24 Apr 13 09:07:32 volumio dhcpcd[781]: eth0: changing default route via 192.168.1.254 Apr 13 09:07:32 volumio avahi-daemon[704]: Registering new address record for 192.168.1.74 on eth0.IPv4. Apr 13 09:07:32 volumio ntpd[1144]: ntpd exiting on signal 15 (Terminated) Apr 13 09:07:32 volumio systemd[1]: Stopping Network Time Service... Apr 13 09:07:32 volumio systemd[1]: ntp.service: Succeeded. Apr 13 09:07:32 volumio systemd[1]: Stopped Network Time Service. Apr 13 09:07:32 volumio systemd[1]: Starting Network Time Service... Apr 13 09:07:32 volumio ntpd[2163]: ntpd 4.2.8p12@1.3728-o (1): Starting Apr 13 09:07:32 volumio ntpd[2163]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Apr 13 09:07:32 volumio systemd[1]: Started Network Time Service. Apr 13 09:07:32 volumio ntpd[2169]: proto: precision = 0.045 usec (-24) Apr 13 09:07:32 volumio dhcpcd[781]: eth0: deleting route to 169.254.0.0/16 Apr 13 09:07:32 volumio avahi-daemon[704]: Withdrawing address record for 169.254.71.185 on eth0. Apr 13 09:07:32 volumio avahi-daemon[704]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.71.185. Apr 13 09:07:32 volumio avahi-daemon[704]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.74. Apr 13 09:07:32 volumio ntpd[2169]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Apr 13 09:07:32 volumio ntpd[2169]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Apr 13 09:07:32 volumio ntpd[2169]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 838 days ago Apr 13 09:07:32 volumio ntpd[2169]: Listen and drop on 0 v6wildcard [::]:123 Apr 13 09:07:32 volumio ntpd[2169]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Apr 13 09:07:32 volumio ntpd[2169]: Listen normally on 2 lo 127.0.0.1:123 Apr 13 09:07:32 volumio ntpd[2169]: Listen normally on 3 eth0 192.168.1.74:123 Apr 13 09:07:32 volumio ntpd[2169]: Listening on routing socket on fd #20 for interface updates Apr 13 09:07:32 volumio ntpd[2169]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 09:07:32 volumio ntpd[2169]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Apr 13 09:07:33 volumio ntpd[2169]: Soliciting pool server 51.38.99.44 Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 13 09:07:33 volumio volumio[847]: info: Adding plugin bluetooth to MyMusic Plugins Apr 13 09:07:33 volumio volumio[847]: info: Adding plugin multiroom to MyMusic Plugins Apr 13 09:07:33 volumio volumio[847]: info: Adding plugin metavolumio to MyMusic Plugins Apr 13 09:07:33 volumio volumio[847]: info: Adding plugin cd_controller to MyMusic Plugins Apr 13 09:07:33 volumio volumio[847]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 13 09:07:33 volumio volumio[847]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 13 09:07:33 volumio volumio[847]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 13 09:07:34 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:07:34 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:07:34 volumio volumio[847]: info: Starting MyVolumio Remote Streaming Endpoints Apr 13 09:07:34 volumio volumio[847]: info: MyVolumio login type: Token Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 13 09:07:34 volumio volumio[847]: info: Starting Streaming Service Transparent Proxy Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 13 09:07:34 volumio volumio[847]: info: Streaming services startup Apr 13 09:07:34 volumio volumio[847]: info: Starting Streaming Daemon Apr 13 09:07:34 volumio sudo[2192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 13 09:07:34 volumio sudo[2192]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:07:34 volumio sudo[2192]: pam_unix(sudo:session): session closed for user root Apr 13 09:07:34 volumio volumio[847]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 13 09:07:34 volumio volumio[847]: info: Discovery: adding 98e1fedf-253c-4c2a-a248-81955f48e086 Apr 13 09:07:34 volumio volumio[847]: info: Discovery: Found device Volumio Apr 13 09:07:34 volumio volumio[847]: info: CoreCommandRouter::volumioGetState Apr 13 09:07:34 volumio volumio[847]: info: CorePlayQueue::getTrack 0 Apr 13 09:07:34 volumio volumio[847]: error: Cannot start Volumio Streaming Daemon Apr 13 09:07:34 volumio volumio[847]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 13 09:07:34 volumio volumio[847]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 13 09:07:34 volumio ntpd[2169]: Soliciting pool server 194.57.169.1 Apr 13 09:07:34 volumio ntpd[2169]: Soliciting pool server 51.178.79.86 Apr 13 09:07:34 volumio volumio[847]: STREAMING PROXY: Starting server on port 3245 Apr 13 09:07:34 volumio volumio[847]: Node JS runtime: 14 Apr 13 09:07:34 volumio volumio[847]: error: MyVolumio Custom Token format not valid, refreshing it Apr 13 09:07:35 volumio ntpd[2169]: Soliciting pool server 146.59.88.209 Apr 13 09:07:35 volumio ntpd[2169]: Soliciting pool server 162.159.200.1 Apr 13 09:07:35 volumio ntpd[2169]: Soliciting pool server 162.159.200.123 Apr 13 09:07:35 volumio volumio[847]: info: MyVolumio login type: Token Apr 13 09:07:36 volumio volumio[847]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 13 09:07:36 volumio ntpd[2169]: Soliciting pool server 82.67.41.119 Apr 13 09:07:36 volumio ntpd[2169]: Soliciting pool server 217.182.137.208 Apr 13 09:07:36 volumio ntpd[2169]: Soliciting pool server 37.59.63.125 Apr 13 09:07:36 volumio volumio-time-update[702]: volumio-time-update-util: Date not found in response Apr 13 09:07:36 volumio volumio-time-update[702]: volumio-time-update-util: Retrying in 5 seconds... Apr 13 09:07:36 volumio ntpd[2169]: Soliciting pool server 82.67.126.242 Apr 13 09:07:36 volumio volumio[847]: info: MyVolumio token set successfully Apr 13 09:07:36 volumio volumio[847]: info: MYVOLUMIO: Adding device Apr 13 09:07:36 volumio volumio[847]: info: MYVOLUMIO: Evaluating Server Apr 13 09:07:36 volumio volumio[847]: info: MyVolumio status changed Apr 13 09:07:36 volumio volumio[847]: info: Streaming services startup Apr 13 09:07:36 volumio volumio[847]: info: Starting Streaming Daemon Apr 13 09:07:36 volumio volumio[847]: info: Removing browser output: myVolumio user plan is not superstar Apr 13 09:07:36 volumio volumio[847]: info: Removing audio output: Apr 13 09:07:36 volumio volumio[847]: info: Stoppping Tunnel 1 Apr 13 09:07:36 volumio sudo[2223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 13 09:07:36 volumio sudo[2223]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:07:36 volumio sudo[2223]: pam_unix(sudo:session): session closed for user root Apr 13 09:07:36 volumio sudo[2226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 13 09:07:36 volumio sudo[2226]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:07:36 volumio volumio[847]: error: Cannot start Volumio Streaming Daemon Apr 13 09:07:36 volumio volumio[847]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 13 09:07:36 volumio volumio[847]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 13 09:07:36 volumio sudo[2226]: pam_unix(sudo:session): session closed for user root Apr 13 09:07:36 volumio volumio[847]: info: Remote SSH Stopped Apr 13 09:07:37 volumio volumio[847]: info: Setting Geolocation for MyVolumio to eu4 Apr 13 09:07:37 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:07:37 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:07:37 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:07:37 volumio ntpd[2169]: Soliciting pool server 37.187.150.174 Apr 13 09:07:37 volumio ntpd[2169]: Soliciting pool server 51.68.44.27 Apr 13 09:07:37 volumio ntpd[2169]: Soliciting pool server 51.75.18.118 Apr 13 09:07:37 volumio volumio[847]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 13 09:07:38 volumio volumio[847]: info: Updating MyVolumio device info Apr 13 09:07:38 volumio volumio[847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 09:07:38 volumio ntpd[2169]: Soliciting pool server 82.64.84.116 Apr 13 09:07:38 volumio ntpd[2169]: Soliciting pool server 82.65.248.56 Apr 13 09:07:38 volumio volumio[847]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 13 09:07:39 volumio ntpd[2169]: Soliciting pool server 5.39.80.51 Apr 13 09:07:39 volumio ntpd[2169]: Soliciting pool server 2001:418:3ff::1:53 Apr 13 09:07:41 volumio volumio-time-update[702]: volumio-time-update-util: Fetching time from Volumio... Apr 13 09:07:27 volumio ntpd[2169]: receive: Unexpected origin timestamp 0xeba5fd5d.6fc28866 does not match aorg 0000000000.00000000 from server@37.59.63.125 xmt 0xeba5fd4f.84e0d95c Apr 13 09:07:27 volumio ntpd[2169]: receive: Unexpected origin timestamp 0xeba5fd5d.6fc23e93 does not match aorg 0000000000.00000000 from server@217.182.137.208 xmt 0xeba5fd4f.844fa33a Apr 13 09:07:27 volumio ntpd[2169]: receive: Unexpected origin timestamp 0xeba5fd5d.6fc200cd does not match aorg 0000000000.00000000 from server@37.187.150.174 xmt 0xeba5fd4f.84cb439e Apr 13 09:07:27 volumio ntpd[2169]: receive: Unexpected origin timestamp 0xeba5fd5d.6fbfef45 does not match aorg 0000000000.00000000 from server@82.65.248.56 xmt 0xeba5fd4f.85d1dc8e Apr 13 09:07:27 volumio ntpd[2169]: receive: Unexpected origin timestamp 0xeba5fd5d.6fc34055 does not match aorg 0000000000.00000000 from server@51.38.99.44 xmt 0xeba5fd4f.84cd52aa Apr 13 09:07:27 volumio volumio[847]: info: MYVOLUMIO: Adding device Apr 13 09:07:27 volumio volumio[847]: info: MYVOLUMIO: Evaluating Server Apr 13 09:07:27 volumio volumio-time-update[702]: volumio-time-update-util: Setting system time to: 2025-04-13 09:07:27 Apr 13 09:07:27 volumio sudo[2258]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-04-13 09:07:27 Apr 13 09:07:27 volumio sudo[2258]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 13 09:07:27 volumio dbus-daemon[710]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.15' (uid=0 pid=2260 comm="timedatectl set-time 2025-04-13 09:07:27 ") Apr 13 09:07:27 volumio systemd[1]: Starting Time & Date Service... Apr 13 09:07:27 volumio dbus-daemon[710]: [system] Successfully activated service 'org.freedesktop.timedate1' Apr 13 09:07:27 volumio systemd[1]: Started Time & Date Service. Apr 13 09:07:27 volumio systemd-timedated[2264]: Changed local time to Sun Apr 13 09:07:27 2025 Apr 13 09:07:27 volumio sudo[2258]: pam_unix(sudo:session): session closed for user root Apr 13 09:07:27 volumio volumio-time-update[702]: volumio-time-update-util: System time updated successfully. Apr 13 09:07:27 volumio systemd[1]: Started Volumio Time Update Utility. Apr 13 09:07:27 volumio systemd[1]: Reached target Multi-User System. Apr 13 09:07:27 volumio systemd[1]: Reached target Graphical Interface. Apr 13 09:07:27 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Apr 13 09:07:27 volumio volumio[847]: error: Failed to ping endpoint eu7.myvolumio.org : unknown error Apr 13 09:07:27 volumio volumio[847]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 09:07:27 volumio volumio[847]: Error: Unable to resolve or reject the same promise twice Apr 13 09:07:27 volumio volumio[847]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 13 09:07:27 volumio volumio[847]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Apr 13 09:07:27 volumio volumio[847]: at Socket.emit (events.js:412:35) Apr 13 09:07:27 volumio volumio[847]: at endReadableNT (internal/streams/readable.js:1333:12) Apr 13 09:07:27 volumio volumio[847]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Apr 13 09:07:27 volumio volumio[847]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 09:07:27 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Apr 13 09:07:27 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Apr 13 09:07:27 volumio systemd[1]: Startup finished in 11.290s (firmware) + 1.127s (loader) + 6.613s (kernel) + 1min 46.794s (userspace) = 2min 5.824s. Apr 13 09:07:27 volumio sudo[2286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-13 09:06 Apr 13 09:07:27 volumio sudo[2286]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 12:15:38 PM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9e0e048b157c8fb0f19240808f3da58b"