May 23 08:03:00 volumio volumio[1159]: Starting albumart workers May 23 08:03:00 volumio volumio[1161]: Starting albumart workers May 23 08:03:00 volumio volumio[1158]: Starting albumart workers May 23 08:03:00 volumio volumio[884]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=0.069&uuid=03a0a3a4cf81b5207182b644467293eb" http://updates.volumio.org/downloader-v1/track-device May 23 08:03:00 volumio volumio[884]: % Total % Received % Xferd Average Speed Time Time Time Current May 23 08:03:00 volumio volumio[884]: Dload Upload Total Spent Left Speed May 23 08:03:00 volumio volumio[884]: [237B blob data] May 23 08:03:00 volumio volumio[884]: curl: (7) Failed to connect to updates.volumio.org port 80 after 5087 ms: Couldn't connect to server May 23 08:03:00 volumio volumio[884]: retrying in 5 seconds, trial 0 May 23 08:03:00 volumio volumio[884]: info: Volumio Calling Home May 23 08:03:01 volumio systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... May 23 08:03:01 volumio dnsmasq[910]: exiting on receipt of SIGTERM May 23 08:03:02 volumio firststart.sh[979]: Creating SSH2 RSA key; this may take some time ... May 23 08:03:02 volumio systemd[1]: dnsmasq.service: Deactivated successfully. May 23 08:03:02 volumio systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. May 23 08:03:02 volumio systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... May 23 08:03:02 volumio firststart.sh[1397]: 3072 SHA256:t5j+nb5D6puIDBjL1MjTIAUBy5l7rv97i9ehhmwPgzs root@volumio (RSA) May 23 08:03:03 volumio dhcpcd[656]: wlan0: carrier lost May 23 08:03:03 volumio systemd[1]: hostapd.service: Deactivated successfully. May 23 08:03:03 volumio systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. May 23 08:03:03 volumio dhcpcd[656]: wlan0: deleting route to 169.254.0.0/16 May 23 08:03:03 volumio dhcpcd[656]: wlan0: deleting default route May 23 08:03:03 volumio firststart.sh[979]: Creating SSH2 DSA key; this may take some time ... May 23 08:03:03 volumio avahi-daemon[585]: Withdrawing address record for 169.254.3.227 on wlan0. May 23 08:03:03 volumio firststart.sh[1425]: 1024 SHA256:ugMBdkpiLKwzRGOo3bPyc09Y1VU5e1+bgO6wWWM0Hso root@volumio (DSA) May 23 08:03:03 volumio firststart.sh[979]: Creating SSH2 ECDSA key; this may take some time ... May 23 08:03:03 volumio firststart.sh[1429]: 256 SHA256:S42inQHGG5mYvIcjDEAGpbU6H/MFSz6CGfwkBEo0qbI root@volumio (ECDSA) May 23 08:03:03 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:03 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:03:03 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:03:03 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:03:03 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:03:03 volumio sudo[1410]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 23 08:03:04 volumio sudo[1410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:03:04 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:03:04 volumio avahi-daemon[585]: Withdrawing address record for 192.168.211.1 on wlan0. May 23 08:03:04 volumio avahi-daemon[585]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. May 23 08:03:04 volumio sudo[1410]: pam_unix(sudo:session): session closed for user root May 23 08:03:04 volumio avahi-daemon[585]: Interface wlan0.IPv4 no longer relevant for mDNS. May 23 08:03:04 volumio welcome[1435]: Resolved ip:[0] May 23 08:03:04 volumio volumio[884]: info: Discovery: A device disappeared from network May 23 08:03:04 volumio volumio[884]: info: Discovery: Browse raised the following error TypeError: Cannot read properties of undefined (reading 'toLowerCase') May 23 08:03:04 volumio sudo[1445]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 23 08:03:04 volumio sudo[1445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:03:04 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:03:04 volumio mpd[1243]: 2025-05-23T08:03:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 23 08:03:04 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:04 volumio mpd[1243]: 2025-05-23T08:03:04 exception: Database corrupted May 23 08:03:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 23 08:03:04 volumio sudo[1215]: pam_unix(sudo:session): session closed for user root May 23 08:03:04 volumio sudo[1227]: pam_unix(sudo:session): session closed for user root May 23 08:03:04 volumio volumio[884]: info: Completed starting Core Plugins May 23 08:03:04 volumio volumio[884]: info: ------------------------------------------- May 23 08:03:04 volumio volumio[884]: info: ----- MyVolumio plugins startup ---- May 23 08:03:04 volumio volumio[884]: info: ------------------------------------------- May 23 08:03:04 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:04 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:03:04 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:03:04 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:03:04 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:03:04 volumio sudo[1445]: pam_unix(sudo:session): session closed for user root May 23 08:03:04 volumio volumio[884]: info: [MyVolumio PluginManager] Fetching plans data.... May 23 08:03:05 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:03:05 volumio welcome[1459]: Resolved ip:[0] May 23 08:03:05 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:03:05 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:05 volumio firststart.sh[1455]: insserv: warning: current start runlevel(s) (empty) of script `ssh' overrides LSB defaults (2 3 4 5). May 23 08:03:05 volumio firststart.sh[1455]: insserv: warning: current stop runlevel(s) (2 3 4 5) of script `ssh' overrides LSB defaults (empty). May 23 08:03:05 volumio firststart.sh[1455]: insserv: Script `ssh' has overlapping Default-Start and Default-Stop runlevels (2 3 4 5) and (2 3 4 5). This should be fixed. May 23 08:03:05 volumio firststart.sh[1455]: insserv: warning: current start runlevel(s) (empty) of script `ssh' overrides LSB defaults (2 3 4 5). May 23 08:03:05 volumio systemd[1]: Reloading. May 23 08:03:05 volumio sudo[1485]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 23 08:03:05 volumio sudo[1485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:06 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 23 08:03:06 volumio sudo[1485]: pam_unix(sudo:session): session closed for user root May 23 08:03:06 volumio sudo[1487]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 23 08:03:06 volumio sudo[1487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:06 volumio volumio[884]: error: MPD error: The expression evaluated to a falsy value: May 23 08:03:06 volumio volumio[884]: assert.ok(self.idling) May 23 08:03:06 volumio volumio[884]: error: The expression evaluated to a falsy value: May 23 08:03:06 volumio volumio[884]: assert.ok(self.idling) May 23 08:03:06 volumio ntpd[770]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 23 08:03:06 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:06 volumio ntpd[770]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 May 23 08:03:06 volumio sudo[1487]: pam_unix(sudo:session): session closed for user root May 23 08:03:06 volumio volumio[884]: verbose: ControllerMpd::sendMpdCommand status May 23 08:03:06 volumio volumio[884]: info: May 23 08:03:06 volumio volumio[884]: ---------------------------- MPD announces state update: update May 23 08:03:06 volumio volumio[884]: info: ControllerMpd::getState May 23 08:03:06 volumio volumio[884]: verbose: ControllerMpd::sendMpdCommand status May 23 08:03:06 volumio volumio[884]: error: updateQueue error: null May 23 08:03:06 volumio volumio[884]: info: Discovery: adding e8a9d5e9-36df-460d-8b8a-f115af546a24 May 23 08:03:06 volumio volumio[884]: info: Discovery: Found device Volumio May 23 08:03:06 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:06 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:06 volumio sudo[1513]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 23 08:03:06 volumio sudo[1513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:06 volumio sudo[1513]: pam_unix(sudo:session): session closed for user root May 23 08:03:06 volumio volumio[884]: info: Discovery: this is already registered, e8a9d5e9-36df-460d-8b8a-f115af546a24 May 23 08:03:06 volumio volumio[884]: info: Discovery: Found device Volumio May 23 08:03:06 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:06 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:06 volumio volumio[884]: info: MPD running with PID1243 May 23 08:03:06 volumio volumio[884]: ,establishing connection May 23 08:03:06 volumio volumio[884]: info: sendMpdCommand status took 194 milliseconds May 23 08:03:06 volumio volumio[884]: info: sendMpdCommand status took 188 milliseconds May 23 08:03:06 volumio volumio[884]: verbose: ControllerMpd::parseState May 23 08:03:06 volumio sudo[1515]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 23 08:03:06 volumio sudo[1515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:07 volumio ntpd[770]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:07 volumio ntpd[770]: IO: Deleting interface #3 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=44 secs May 23 08:03:07 volumio ntpd[770]: IO: Deleting interface #4 wlan0, 169.254.3.227#123, interface stats: received=0, sent=0, dropped=0, active_time=32 secs May 23 08:03:07 volumio ntpd[770]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 23 08:03:07 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:07 volumio ntpd[770]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 May 23 08:03:07 volumio volumio[884]: info: Command Router : Notfying DB Updatefalse May 23 08:03:07 volumio volumio[884]: info: CoreCommandRouter::Close All Modals sent May 23 08:03:07 volumio volumio[884]: verbose: ControllerMpd::parseState May 23 08:03:07 volumio volumio[884]: info: ControllerMpd::pushState May 23 08:03:07 volumio volumio[884]: info: CoreCommandRouter::servicePushState May 23 08:03:07 volumio volumio[884]: info: CoreStateMachine::pushState May 23 08:03:07 volumio sudo[1515]: pam_unix(sudo:session): session closed for user root May 23 08:03:07 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:07 volumio volumio[884]: info: CoreCommandRouter::volumioPushState May 23 08:03:07 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:07 volumio volumio[884]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 23 08:03:07 volumio volumio[884]: verbose: CURRENT POSITION 0 May 23 08:03:07 volumio volumio[884]: info: CoreStateMachine::syncState stateService stop May 23 08:03:07 volumio volumio[884]: info: CoreStateMachine::syncState currentStatus stop May 23 08:03:07 volumio volumio[884]: info: CoreStateMachine::pushState May 23 08:03:07 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:07 volumio volumio[884]: info: CoreCommandRouter::volumioPushState May 23 08:03:07 volumio volumio[884]: info: No code May 23 08:03:07 volumio volumio[884]: info: CoreStateMachine::pushState May 23 08:03:07 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:07 volumio volumio[884]: info: CoreCommandRouter::volumioPushState May 23 08:03:07 volumio sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 23 08:03:07 volumio sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:07 volumio sudo[1525]: pam_unix(sudo:session): session closed for user root May 23 08:03:07 volumio sudo[1527]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US May 23 08:03:07 volumio sudo[1527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:07 volumio sudo[1527]: pam_unix(sudo:session): session closed for user root May 23 08:03:07 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:07 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:07 volumio volumio[884]: info: ------------------------------ 1173ms May 23 08:03:08 volumio volumio[884]: info: Discovery: this is already registered, e8a9d5e9-36df-460d-8b8a-f115af546a24 May 23 08:03:08 volumio volumio[884]: info: Discovery: Found device Volumio May 23 08:03:08 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:08 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:08 volumio volumio[884]: info: Discovery: this is already registered, e8a9d5e9-36df-460d-8b8a-f115af546a24 May 23 08:03:08 volumio volumio[884]: info: Discovery: Found device Volumio May 23 08:03:08 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:08 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:08 volumio volumio[884]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 23 08:03:08 volumio volumio[884]: error: updateQueue error: null May 23 08:03:09 volumio volumio[884]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 23 08:03:09 volumio sudo[1537]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 23 08:03:09 volumio sudo[1537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:03:09 volumio sudo[1537]: pam_unix(sudo:session): session closed for user root May 23 08:03:09 volumio sudo[1540]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 23 08:03:09 volumio sudo[1540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:03:09 volumio sudo[1540]: pam_unix(sudo:session): session closed for user root May 23 08:03:09 volumio avahi-daemon[585]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. May 23 08:03:09 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 23 08:03:09 volumio avahi-daemon[585]: New relevant interface wlan0.IPv4 for mDNS. May 23 08:03:09 volumio avahi-daemon[585]: Registering new address record for 192.168.211.1 on wlan0.IPv4. May 23 08:03:10 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:10 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:03:10 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:03:10 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:03:10 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:03:10 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:10 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:03:10 volumio welcome[1550]: Resolved ip:[1] 192.168.211.1 May 23 08:03:10 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:03:10 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:10 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:10 volumio systemd[1]: Starting hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... May 23 08:03:10 volumio volumio[884]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 23 08:03:10 volumio dhcpcd[656]: wlan0: carrier acquired May 23 08:03:10 volumio hostapd[1555]: wlan0: interface state UNINITIALIZED->ENABLED May 23 08:03:10 volumio hostapd[1555]: wlan0: AP-ENABLED May 23 08:03:10 volumio systemd[1]: hostapd.service: Can't open PID file /run/hostapd.pid (yet?) after start: No such file or directory May 23 08:03:10 volumio systemd[1]: Started hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. May 23 08:03:10 volumio dhcpcd[656]: wlan0: IAID 67:15:68:e7 May 23 08:03:10 volumio systemd[1]: Starting dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... May 23 08:03:10 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 23 08:03:10 volumio systemd[1]: Reloading. May 23 08:03:10 volumio iwconfig[1579]: Error for wireless request "Set Power Management" (8B2C) : May 23 08:03:10 volumio iwconfig[1579]: SET failed on device wlan0 ; Invalid argument. May 23 08:03:10 volumio dhcpcd[656]: wlan0: soliciting an IPv6 router May 23 08:03:10 volumio dbus-daemon[587]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.23' (uid=0 pid=1576 comm="timedatectl show --property=NTPSynchronized --valu") May 23 08:03:11 volumio volumio[884]: info: Discovery: this is already registered, e8a9d5e9-36df-460d-8b8a-f115af546a24 May 23 08:03:11 volumio volumio[884]: info: Discovery: Found device Volumio May 23 08:03:11 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:11 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:11 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:11 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:12 volumio ntpd[770]: IO: Listen normally on 5 wlan0 192.168.211.1:123 May 23 08:03:12 volumio ntpd[770]: IO: new interface(s) found: waking up resolver May 23 08:03:12 volumio ntpd[770]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:12 volumio ntpd[770]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 23 08:03:12 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:12 volumio ntpd[770]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 May 23 08:03:12 volumio dhcpcd[656]: wlan0: soliciting a DHCP lease May 23 08:03:12 volumio systemd[1]: wireless.service: Deactivated successfully. May 23 08:03:12 volumio systemd[1]: Started wireless.service - Wireless Services. May 23 08:03:12 volumio systemd[1]: wireless.service: Consumed 24.161s CPU time. May 23 08:03:12 volumio sudo[1317]: pam_unix(sudo:session): session closed for user root May 23 08:03:12 volumio dnsmasq[1612]: started, version 2.90 cachesize 150 May 23 08:03:12 volumio dnsmasq[1612]: compile time options: IPv6 GNU-getopt DBus no-UBus i18n IDN2 DHCP DHCPv6 no-Lua TFTP conntrack ipset nftset auth cryptohash DNSSEC loop-detect inotify dumpfile May 23 08:03:12 volumio dnsmasq-dhcp[1612]: DHCP, IP range 192.168.211.100 -- 192.168.211.200, lease time 1d May 23 08:03:12 volumio dnsmasq[1612]: reading /etc/resolv.conf May 23 08:03:12 volumio dnsmasq[1612]: using nameserver 208.67.222.222#53 May 23 08:03:12 volumio dnsmasq[1612]: using nameserver 208.67.220.220#53 May 23 08:03:12 volumio dnsmasq[1612]: read /etc/hosts - 18 names May 23 08:03:12 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 23 08:03:12 volumio systemd[1]: Started dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. May 23 08:03:13 volumio firststart.sh[1610]: rescue-ssh.target is a disabled or a static unit not running, not starting it. May 23 08:03:13 volumio ntpd[770]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:13 volumio ntpd[770]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 May 23 08:03:13 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:13 volumio ntpd[770]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 May 23 08:03:13 volumio firststart.sh[1610]: ssh.service is a disabled or a static unit not running, not starting it. May 23 08:03:13 volumio dbus-daemon[587]: [system] Successfully activated service 'org.freedesktop.timedate1' May 23 08:03:13 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 23 08:03:13 volumio setdatetime-helper.sh[1570]: Time is already synchronized. May 23 08:03:13 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 23 08:03:13 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 23 08:03:13 volumio volumio[884]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory May 23 08:03:13 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 08:03:13 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 23 08:03:13 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 08:03:13 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 23 08:03:14 volumio ntpd[770]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:14 volumio ntpd[770]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 23 08:03:14 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:14 volumio ntpd[770]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 May 23 08:03:14 volumio systemd[1]: Reloading. May 23 08:03:15 volumio ntpd[770]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:15 volumio ntpd[770]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 23 08:03:15 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:15 volumio ntpd[770]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 May 23 08:03:15 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:15 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:16 volumio firststart.sh[1671]: ssh.socket is a disabled or a static unit not running, not starting it. May 23 08:03:17 volumio dhcpcd[656]: wlan0: probing for an IPv4LL address May 23 08:03:17 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection May 23 08:03:17 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo May 23 08:03:17 volumio sudo[1679]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 08:03:17 volumio sudo[1679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:18 volumio sudo[1679]: pam_unix(sudo:session): session closed for user root May 23 08:03:18 volumio firststart.sh[885]: Enabling SSH for first boot May 23 08:03:19 volumio systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... May 23 08:03:19 volumio sshd[1683]: Server listening on 0.0.0.0 port 22. May 23 08:03:19 volumio sshd[1683]: Server listening on :: port 22. May 23 08:03:19 volumio systemd[1]: Started ssh.service - OpenBSD Secure Shell server. May 23 08:03:19 volumio firststart.sh[885]: Disabling firststart service May 23 08:03:19 volumio systemctl[1684]: Removed "/etc/systemd/system/multi-user.target.wants/firststart.service". May 23 08:03:19 volumio systemd[1]: Reloading. May 23 08:03:20 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:20 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 23 08:03:21 volumio firststart.sh[885]: Finalizing May 23 08:03:21 volumio systemd[1]: firststart.service: Deactivated successfully. May 23 08:03:21 volumio systemd[1]: firststart.service: Consumed 39.968s CPU time. May 23 08:03:22 volumio dhcpcd[656]: wlan0: using IPv4LL address 169.254.3.227 May 23 08:03:22 volumio avahi-daemon[585]: Registering new address record for 169.254.3.227 on wlan0.IPv4. May 23 08:03:22 volumio dhcpcd[656]: wlan0: adding route to 169.254.0.0/16 May 23 08:03:22 volumio dhcpcd[656]: wlan0: adding default route May 23 08:03:22 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:22 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:03:22 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:03:22 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:03:22 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:03:22 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:03:22 volumio welcome[1713]: Resolved ip:[2] 192.168.211.1 169.254.3.227 May 23 08:03:22 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:03:22 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:03:22 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart May 23 08:03:22 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart May 23 08:03:22 volumio volumio[884]: info: Refreshing Cached IP Addresses May 23 08:03:22 volumio sudo[1720]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 23 08:03:22 volumio sudo[1720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:23 volumio sudo[1722]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli May 23 08:03:23 volumio sudo[1722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:23 volumio sudo[1722]: pam_unix(sudo:session): session closed for user root May 23 08:03:23 volumio sudo[1720]: pam_unix(sudo:session): session closed for user root May 23 08:03:23 volumio sudo[1723]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 08:03:23 volumio sudo[1723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:23 volumio sudo[1723]: pam_unix(sudo:session): session closed for user root May 23 08:03:24 volumio ntpd[770]: IO: Listen normally on 6 wlan0 169.254.3.227:123 May 23 08:03:24 volumio ntpd[770]: IO: new interface(s) found: waking up resolver May 23 08:03:24 volumio ntpd[770]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:24 volumio volumio[884]: error: MyVolumio Plugin failed to start in a timely fashion May 23 08:03:24 volumio volumio[884]: [Metrics] CommandRouter: 56s 567.31ms May 23 08:03:24 volumio volumio[884]: info: CoreCommandRouter::volumiosetStartupVolume May 23 08:03:24 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 08:03:24 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 08:03:25 volumio volumio[884]: info: CoreCommandRouter::Close All Modals sent May 23 08:03:25 volumio volumio[884]: info: CoreCommandRouter::Close All Modals sent May 23 08:03:26 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 23 08:03:26 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 23 08:03:26 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 23 08:03:26 volumio volumio[884]: info: Version has changed, forcing UI Reload May 23 08:03:26 volumio volumio[884]: info: CoreCommandRouter::Reload Ui May 23 08:03:32 volumio volumio[884]: info: BOOT COMPLETED May 23 08:03:33 volumio sudo[1757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 23 08:03:33 volumio sudo[1757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:33 volumio sudo[1755]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 08:03:33 volumio sudo[1753]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 23 08:03:33 volumio sudo[1753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:33 volumio sudo[1755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:03:33 volumio sudo[1755]: pam_unix(sudo:session): session closed for user root May 23 08:03:33 volumio sudo[1757]: pam_unix(sudo:session): session closed for user root May 23 08:03:33 volumio volumio[884]: info: Upmpdcli Daemon Started May 23 08:03:33 volumio sudo[1753]: pam_unix(sudo:session): session closed for user root May 23 08:03:35 volumio ntpd[770]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 23 08:03:35 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:35 volumio ntpd[770]: DNS: dns_take_status: 3.debian.pool.ntp.org=>error, 12 May 23 08:03:36 volumio ntpd[770]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:36 volumio volumio[884]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=0.069&uuid=03a0a3a4cf81b5207182b644467293eb" http://updates.volumio.org/downloader-v1/track-device May 23 08:03:36 volumio volumio[884]: % Total % Received % Xferd Average Speed Time Time Time Current May 23 08:03:36 volumio volumio[884]: Dload Upload Total Spent Left Speed May 23 08:03:36 volumio volumio[884]: [1.9K blob data] May 23 08:03:36 volumio volumio[884]: curl: (7) Failed to connect to updates.volumio.org port 80 after 22759 ms: Couldn't connect to server May 23 08:03:36 volumio volumio[884]: retrying in 5 seconds, trial 1 May 23 08:03:36 volumio volumio[884]: info: Volumio Calling Home May 23 08:03:39 volumio hostapd[1562]: wlan0: STA 4e:62:e2:c3:6d:f3 IEEE 802.11: associated May 23 08:03:39 volumio hostapd[1562]: wlan0: STA 4e:62:e2:c3:6d:f3 RADIUS: starting accounting session CB40250936C88789 May 23 08:03:43 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 23 08:03:47 volumio ntpd[770]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 May 23 08:03:47 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:47 volumio ntpd[770]: DNS: dns_take_status: 2.debian.pool.ntp.org=>error, 12 May 23 08:03:48 volumio ntpd[770]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPDISCOVER(wlan0) 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPOFFER(wlan0) 192.168.211.191 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPDISCOVER(wlan0) 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPOFFER(wlan0) 192.168.211.191 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPDISCOVER(wlan0) 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPOFFER(wlan0) 192.168.211.191 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPREQUEST(wlan0) 192.168.211.191 4e:62:e2:c3:6d:f3 May 23 08:03:48 volumio dnsmasq-dhcp[1612]: DHCPACK(wlan0) 192.168.211.191 4e:62:e2:c3:6d:f3 S23-FE-milik-ardiyan May 23 08:03:49 volumio volumio[884]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=0.069&uuid=03a0a3a4cf81b5207182b644467293eb" http://updates.volumio.org/downloader-v1/track-device May 23 08:03:49 volumio volumio[884]: % Total % Received % Xferd Average Speed Time Time Time Current May 23 08:03:49 volumio volumio[884]: Dload Upload Total Spent Left Speed May 23 08:03:49 volumio volumio[884]: [316B blob data] May 23 08:03:49 volumio volumio[884]: curl: (7) Failed to connect to updates.volumio.org port 80 after 3104 ms: Couldn't connect to server May 23 08:03:49 volumio volumio[884]: retrying in 5 seconds, trial 2 May 23 08:03:49 volumio volumio[884]: info: Volumio Calling Home May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 08:03:52 volumio volumio[884]: info: Discovery: Getting this device information May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:52 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 08:03:52 volumio volumio[884]: verbose: New Socket.io Connection to 192.168.211.1:3000 from 192.168.211.191 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:52 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 23 08:03:52 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache May 23 08:03:52 volumio volumio-remote-updater[596]: No test mode May 23 08:03:52 volumio volumio-remote-updater[596]: No alpha test mode May 23 08:03:53 volumio volumio-remote-updater[596]: curl_easy_perform() failed: Couldn't connect to server May 23 08:03:53 volumio volumio-remote-updater[596]: terminate called after throwing an instance of 'std::invalid_argument' May 23 08:03:53 volumio volumio-remote-updater[596]: what(): parse error - unexpected end of input May 23 08:03:53 volumio systemd[1]: volumio-remote-updater.service: Main process exited, code=killed, status=6/ABRT May 23 08:03:53 volumio systemd[1]: volumio-remote-updater.service: Failed with result 'signal'. May 23 08:03:53 volumio systemd[1]: volumio-remote-updater.service: Scheduled restart job, restart counter is at 1. May 23 08:03:53 volumio systemd[1]: Stopped volumio-remote-updater.service. May 23 08:03:53 volumio systemd[1]: Started volumio-remote-updater.service. May 23 08:03:53 volumio volumio-remote-updater[1802]: Error: No active session May 23 08:03:53 volumio volumio-remote-updater[1802]: [2025-05-23 08:03:53] [connect] Successful connection May 23 08:03:53 volumio volumio-remote-updater[1802]: [2025-05-23 08:03:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747987433 101 May 23 08:03:53 volumio volumio[884]: 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 May 23 08:03:55 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 23 08:03:55 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 23 08:03:55 volumio volumio[884]: info: Discovery: Getting this device information May 23 08:03:55 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:03:55 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:03:55 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 08:03:58 volumio ntpd[770]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 23 08:03:58 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:03:58 volumio ntpd[770]: DNS: dns_take_status: 1.debian.pool.ntp.org=>error, 12 May 23 08:03:59 volumio ntpd[770]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:04:06 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings May 23 08:04:06 volumio volumio[884]: info: Saving new wireless network May 23 08:04:06 volumio sudo[1821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf May 23 08:04:06 volumio sudo[1821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:06 volumio sudo[1821]: pam_unix(sudo:session): session closed for user root May 23 08:04:07 volumio volumio[884]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 23 08:04:07 volumio volumio[884]: info: Discovery: Restarting Advertising due to device name change May 23 08:04:07 volumio sudo[1828]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service May 23 08:04:07 volumio sudo[1828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:07 volumio systemd[1]: Starting wireless.service - Wireless Services... May 23 08:04:08 volumio volumio[884]: info: Discovery: A device disappeared from network May 23 08:04:08 volumio volumio[884]: info: Discovery: Device volumio disappeared from network May 23 08:04:08 volumio volumio[884]: info: Discovery: A device disappeared from network May 23 08:04:09 volumio systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... May 23 08:04:09 volumio dnsmasq[1612]: exiting on receipt of SIGTERM May 23 08:04:09 volumio systemd[1]: dnsmasq.service: Deactivated successfully. May 23 08:04:09 volumio systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. May 23 08:04:09 volumio hostapd[1562]: wlan0: STA 4e:62:e2:c3:6d:f3 IEEE 802.11: disassociated May 23 08:04:09 volumio systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... May 23 08:04:09 volumio dhcpcd[656]: wlan0: carrier lost May 23 08:04:10 volumio systemd[1]: hostapd.service: Deactivated successfully. May 23 08:04:10 volumio systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. May 23 08:04:10 volumio avahi-daemon[585]: Withdrawing address record for 169.254.3.227 on wlan0. May 23 08:04:10 volumio dhcpcd[656]: wlan0: deleting route to 169.254.0.0/16 May 23 08:04:10 volumio dhcpcd[656]: wlan0: deleting default route May 23 08:04:10 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:04:10 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:04:10 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:04:10 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:04:10 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:04:10 volumio sudo[1878]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 23 08:04:10 volumio sudo[1878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:04:10 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:04:10 volumio avahi-daemon[585]: Withdrawing address record for 192.168.211.1 on wlan0. May 23 08:04:10 volumio avahi-daemon[585]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. May 23 08:04:10 volumio sudo[1878]: pam_unix(sudo:session): session closed for user root May 23 08:04:10 volumio avahi-daemon[585]: Interface wlan0.IPv4 no longer relevant for mDNS. May 23 08:04:10 volumio welcome[1881]: Resolved ip:[0] May 23 08:04:10 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:04:10 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:04:10 volumio sudo[1886]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 23 08:04:10 volumio sudo[1886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:04:10 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:04:10 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:04:10 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:04:10 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:04:10 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:04:10 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:04:10 volumio sudo[1886]: pam_unix(sudo:session): session closed for user root May 23 08:04:10 volumio welcome[1891]: Resolved ip:[0] May 23 08:04:10 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:04:10 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:04:11 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 23 08:04:11 volumio dbus-daemon[587]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.25' (uid=0 pid=1899 comm="timedatectl show --property=NTPSynchronized --valu") May 23 08:04:11 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 23 08:04:11 volumio dbus-daemon[587]: [system] Successfully activated service 'org.freedesktop.timedate1' May 23 08:04:11 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 23 08:04:11 volumio setdatetime-helper.sh[1898]: Time is already synchronized. May 23 08:04:11 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 23 08:04:11 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 23 08:04:11 volumio sudo[1906]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 23 08:04:11 volumio sudo[1906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:11 volumio sudo[1906]: pam_unix(sudo:session): session closed for user root May 23 08:04:11 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 23 08:04:11 volumio sudo[1908]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 23 08:04:11 volumio sudo[1908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:11 volumio sudo[1908]: pam_unix(sudo:session): session closed for user root May 23 08:04:11 volumio sudo[1916]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 23 08:04:11 volumio sudo[1916]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:11 volumio sudo[1916]: pam_unix(sudo:session): session closed for user root May 23 08:04:11 volumio sudo[1918]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 23 08:04:11 volumio sudo[1918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:12 volumio volumio[884]: info: Discovery: Started advertising with name: Volumio May 23 08:04:12 volumio sudo[1918]: pam_unix(sudo:session): session closed for user root May 23 08:04:12 volumio sudo[1925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 23 08:04:12 volumio sudo[1925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:12 volumio sudo[1925]: pam_unix(sudo:session): session closed for user root May 23 08:04:12 volumio sudo[1927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US May 23 08:04:12 volumio sudo[1927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:12 volumio sudo[1927]: pam_unix(sudo:session): session closed for user root May 23 08:04:12 volumio sudo[1935]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 23 08:04:12 volumio sudo[1935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:04:12 volumio sudo[1935]: pam_unix(sudo:session): session closed for user root May 23 08:04:12 volumio sudo[1937]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 23 08:04:12 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:04:13 volumio ntpd[770]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 23 08:04:13 volumio ntpd[770]: DNS: dns_check: DNS error: -11, System error May 23 08:04:13 volumio ntpd[770]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 May 23 08:04:13 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root May 23 08:04:13 volumio volumio[884]: info: Discovery: adding e8a9d5e9-36df-460d-8b8a-f115af546a24 May 23 08:04:13 volumio volumio[884]: info: Discovery: Found device Volumio May 23 08:04:13 volumio volumio[884]: info: CoreCommandRouter::volumioGetState May 23 08:04:13 volumio volumio[884]: info: CorePlayQueue::getTrack 0 May 23 08:04:13 volumio sudo[1944]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd May 23 08:04:13 volumio sudo[1944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:04:13 volumio dhcpcd[656]: control command: /sbin/dhcpcd May 23 08:04:13 volumio sudo[1944]: pam_unix(sudo:session): session closed for user root May 23 08:04:13 volumio dhcpcd[656]: control_free: No such file or directory May 23 08:04:13 volumio dhcpcd[656]: lo: IAID 00:00:00:00 May 23 08:04:13 volumio dhcpcd[656]: lo: adding address fe80::938c:d768:5b51:a131 May 23 08:04:13 volumio dhcpcd[656]: ipv6_addaddr1: Permission denied May 23 08:04:13 volumio dhcpcd[656]: lo: using static address 127.0.0.1/8 May 23 08:04:13 volumio dhcpcd[656]: lo: adding route to 127.0.0.0/8 May 23 08:04:13 volumio systemd[1]: Reached target ip-changed@lo.target - IP Address changed on lo. May 23 08:04:13 volumio wpa_supplicant[1943]: Successfully initialized wpa_supplicant May 23 08:04:13 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 23 08:04:14 volumio wpa_supplicant[1943]: nl80211: kernel reports: Registration to specific type not supported May 23 08:04:14 volumio sudo[1977]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:14 volumio sudo[1977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:14 volumio sudo[1977]: pam_unix(sudo:session): session closed for user root May 23 08:04:14 volumio wpa_supplicant[1974]: wlan0: Trying to associate with 68:ff:7b:00:14:b2 (SSID='IoT' freq=2462 MHz) May 23 08:04:14 volumio wpa_supplicant[1974]: wlan0: Associated with 68:ff:7b:00:14:b2 May 23 08:04:14 volumio wpa_supplicant[1974]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 23 08:04:14 volumio wpa_supplicant[1974]: wlan0: WPA: Key negotiation completed with 68:ff:7b:00:14:b2 [PTK=CCMP GTK=CCMP] May 23 08:04:14 volumio wpa_supplicant[1974]: wlan0: CTRL-EVENT-CONNECTED - Connection to 68:ff:7b:00:14:b2 completed [id=0 id_str=] May 23 08:04:14 volumio dhcpcd[656]: wlan0: carrier acquired May 23 08:04:14 volumio dhcpcd[656]: wlan0: connected to Access Point: IoT May 23 08:04:14 volumio dhcpcd[656]: wlan0: IAID 67:15:68:e7 May 23 08:04:15 volumio dhcpcd[656]: wlan0: soliciting an IPv6 router May 23 08:04:15 volumio sudo[1982]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:15 volumio dhcpcd[656]: wlan0: soliciting a DHCP lease May 23 08:04:15 volumio sudo[1982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:15 volumio sudo[1982]: pam_unix(sudo:session): session closed for user root May 23 08:04:16 volumio ntpd[770]: IO: Deleting interface #5 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=64 secs May 23 08:04:16 volumio ntpd[770]: IO: Deleting interface #6 wlan0, 169.254.3.227#123, interface stats: received=0, sent=0, dropped=0, active_time=52 secs May 23 08:04:16 volumio dhcpcd[656]: wlan0: offered 172.16.231.234 from 172.16.231.1 May 23 08:04:16 volumio dhcpcd[656]: wlan0: probing address 172.16.231.234/24 May 23 08:04:16 volumio sudo[1988]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:16 volumio sudo[1988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:16 volumio sudo[1988]: pam_unix(sudo:session): session closed for user root May 23 08:04:17 volumio sudo[2006]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:17 volumio sudo[2006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:17 volumio sudo[2006]: pam_unix(sudo:session): session closed for user root May 23 08:04:18 volumio sudo[2010]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:18 volumio sudo[2010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:18 volumio sudo[2010]: pam_unix(sudo:session): session closed for user root May 23 08:04:19 volumio sudo[2014]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:19 volumio sudo[2014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:19 volumio sudo[2014]: pam_unix(sudo:session): session closed for user root May 23 08:04:20 volumio sudo[2018]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:20 volumio sudo[2018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:20 volumio sudo[2018]: pam_unix(sudo:session): session closed for user root May 23 08:04:21 volumio dhcpcd[656]: wlan0: leased 172.16.231.234 for 1800 seconds May 23 08:04:21 volumio avahi-daemon[585]: Joining mDNS multicast group on interface wlan0.IPv4 with address 172.16.231.234. May 23 08:04:21 volumio avahi-daemon[585]: New relevant interface wlan0.IPv4 for mDNS. May 23 08:04:21 volumio avahi-daemon[585]: Registering new address record for 172.16.231.234 on wlan0.IPv4. May 23 08:04:21 volumio dhcpcd[656]: wlan0: adding route to 172.16.231.0/24 May 23 08:04:21 volumio dhcpcd[656]: wlan0: adding default route via 172.16.231.1 May 23 08:04:21 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:04:21 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 23 08:04:21 volumio systemd[1]: welcome.service: Deactivated successfully. May 23 08:04:21 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 23 08:04:21 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 23 08:04:21 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 23 08:04:21 volumio welcome[2039]: Resolved ip:[1] 172.16.231.234 May 23 08:04:21 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 23 08:04:21 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 23 08:04:21 volumio sudo[2046]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 23 08:04:21 volumio volumio[884]: compat.c: read() failed: Resource temporarily unavailable May 23 08:04:21 volumio volumio[884]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 08:04:21 volumio sudo[2046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:21 volumio sudo[2046]: pam_unix(sudo:session): session closed for user root May 23 08:04:21 volumio volumio[884]: Error: dns service error: unknown May 23 08:04:21 volumio volumio[884]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { May 23 08:04:21 volumio volumio[884]: errorCode: -65537 May 23 08:04:21 volumio volumio[884]: } May 23 08:04:21 volumio volumio[884]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 08:04:21 volumio sudo[2050]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 08:04:21 volumio sudo[2050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 23 08:04:21 volumio sudo[2050]: pam_unix(sudo:session): session closed for user root May 23 08:04:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 23 08:04:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 23 08:04:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 23 08:04:21 volumio systemd[1]: shairport-sync.service: Consumed 1.939s CPU time. May 23 08:04:21 volumio avahi-daemon[585]: Got SIGTERM, quitting. May 23 08:04:21 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... May 23 08:04:21 volumio avahi-daemon[585]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 172.16.231.234. May 23 08:04:21 volumio avahi-daemon[585]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. May 23 08:04:21 volumio avahi-daemon[585]: avahi-daemon 0.8 exiting. May 23 08:04:22 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. May 23 08:04:22 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. May 23 08:04:22 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... May 23 08:04:22 volumio avahi-daemon[2067]: Process 585 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) May 23 08:04:22 volumio avahi-daemon[2067]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). May 23 08:04:22 volumio avahi-daemon[2067]: Successfully dropped root privileges. May 23 08:04:22 volumio avahi-daemon[2067]: avahi-daemon 0.8 starting up. May 23 08:04:22 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. May 23 08:04:22 volumio avahi-daemon[2067]: Successfully called chroot(). May 23 08:04:22 volumio avahi-daemon[2067]: Successfully dropped remaining capabilities. May 23 08:04:22 volumio avahi-daemon[2067]: No service file found in /etc/avahi/services. May 23 08:04:22 volumio avahi-daemon[2067]: Joining mDNS multicast group on interface wlan0.IPv4 with address 172.16.231.234. May 23 08:04:22 volumio avahi-daemon[2067]: New relevant interface wlan0.IPv4 for mDNS. May 23 08:04:22 volumio avahi-daemon[2067]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. May 23 08:04:22 volumio avahi-daemon[2067]: New relevant interface lo.IPv4 for mDNS. May 23 08:04:22 volumio avahi-daemon[2067]: Network interface enumeration completed. May 23 08:04:22 volumio avahi-daemon[2067]: Registering new address record for 172.16.231.234 on wlan0.IPv4. May 23 08:04:22 volumio avahi-daemon[2067]: Registering new address record for 127.0.0.1 on lo.IPv4. May 23 08:04:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 23 08:04:22 volumio systemd[1]: Started wireless.service - Wireless Services. May 23 08:04:22 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 23 08:04:22 volumio sudo[1828]: pam_unix(sudo:session): session closed for user root May 23 08:04:23 volumio ntpd[770]: IO: Listen normally on 7 wlan0 172.16.231.234:123 May 23 08:04:23 volumio ntpd[770]: IO: new interface(s) found: waking up resolver May 23 08:04:23 volumio ntpd[770]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:04:23 volumio ntpd[770]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 23 08:04:23 volumio ntpd[770]: DNS: Pool taking: 116.12.46.30 May 23 08:04:23 volumio ntpd[770]: DNS: Pool taking: 103.83.142.30 May 23 08:04:23 volumio ntpd[770]: DNS: Pool taking: 103.169.192.230 May 23 08:04:23 volumio ntpd[770]: DNS: Pool taking: 103.134.77.146 May 23 08:04:23 volumio ntpd[770]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 May 23 08:04:23 volumio avahi-daemon[2067]: Server startup complete. Host name is volumio.local. Local service cookie is 1631376008. May 23 08:04:24 volumio ntpd[770]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:04:24 volumio ntpd[770]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 203.89.31.10 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 119.110.74.102 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 27.54.117.72 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 203.114.74.17 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 2001:df0:3140:fac1:b090:12:1980:c01 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 2001:df0:3140:fac1:b090:12:1980:ca71 May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 2600:3c0c::f03c:94ff:fe2d:8f6e May 23 08:04:24 volumio ntpd[770]: DNS: Pool taking: 240b:400b:21:cc00:25e5:c8e2:87ae:8d41 May 23 08:04:24 volumio ntpd[770]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 May 23 08:04:25 volumio ntpd[770]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:04:25 volumio ntpd[770]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 23 08:04:25 volumio ntpd[770]: DNS: Pool taking: 160.30.225.225 May 23 08:04:25 volumio ntpd[770]: DNS: Pool taking: 103.105.57.11 May 23 08:04:25 volumio ntpd[770]: DNS: Pool taking: 116.12.47.30 May 23 08:04:25 volumio ntpd[770]: DNS: Pool taking: 103.169.192.229 May 23 08:04:25 volumio ntpd[770]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 May 23 08:04:25 volumio sudo[2095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-23 08:03' May 23 08:04:25 volumio sudo[2095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 23 08:04:26 volumio ntpd[770]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 23 08:04:26 volumio ntpd[770]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 23 08:04:26 volumio ntpd[770]: DNS: Pool skipping: 160.30.225.225 May 23 08:04:26 volumio ntpd[770]: DNS: Pool taking: 203.89.31.13 May 23 08:04:26 volumio ntpd[770]: DNS: Pool skipping: 119.110.74.102 May 23 08:04:26 volumio ntpd[770]: DNS: Pool skipping: 203.89.31.10 May 23 08:04:26 volumio ntpd[770]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 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="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025" VOLUMIO_VERSION="0.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"