-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Sun 2026-05-31 05:27:51 UTC. -- May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="LikeBebop" May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: SME: Trying to authenticate with 20:c9:d0:a9:b4:32 (SSID='LikeBebop' freq=2412 MHz) May 31 05:26:04 volumio3 kernel: wlan0: authenticate with 20:c9:d0:a9:b4:32 May 31 05:26:04 volumio3 kernel: wlan0: 80 MHz not supported, disabling VHT May 31 05:26:04 volumio3 kernel: wlan0: send auth to 20:c9:d0:a9:b4:32 (try 1/3) May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: Trying to associate with 20:c9:d0:a9:b4:32 (SSID='LikeBebop' freq=2412 MHz) May 31 05:26:04 volumio3 kernel: wlan0: authenticated May 31 05:26:04 volumio3 kernel: wlan0: associate with 20:c9:d0:a9:b4:32 (try 1/3) May 31 05:26:04 volumio3 kernel: wlan0: RX AssocResp from 20:c9:d0:a9:b4:32 (capab=0x1031 status=0 aid=20) May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: Associated with 20:c9:d0:a9:b4:32 May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 31 05:26:04 volumio3 dhcpcd[929]: wlan1: leased 10.0.1.154 for 86400 seconds May 31 05:26:04 volumio3 avahi-daemon[535]: Joining mDNS multicast group on interface wlan1.IPv4 with address 10.0.1.154. May 31 05:26:04 volumio3 kernel: wlan0: associated May 31 05:26:04 volumio3 dhcpcd[929]: wlan1: adding route to 10.0.1.0/24 May 31 05:26:04 volumio3 dhcpcd[929]: wlan1: adding default route via 10.0.1.1 May 31 05:26:04 volumio3 avahi-daemon[535]: New relevant interface wlan1.IPv4 for mDNS. May 31 05:26:04 volumio3 avahi-daemon[535]: Registering new address record for 10.0.1.154 on wlan1.IPv4. May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: WPA: Key negotiation completed with 20:c9:d0:a9:b4:32 [PTK=CCMP GTK=CCMP] May 31 05:26:04 volumio3 wpa_supplicant[898]: wlan0: CTRL-EVENT-CONNECTED - Connection to 20:c9:d0:a9:b4:32 completed [id=0 id_str=] May 31 05:26:04 volumio3 dhcpcd[929]: wlan0: carrier acquired May 31 05:26:04 volumio3 dhcpcd[929]: wlan0: IAID 33:08:f8:41 May 31 05:26:04 volumio3 dhcpcd[929]: wlan0: soliciting an IPv6 router May 31 05:26:04 volumio3 kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by 20:c9:d0:a9:b4:32 May 31 05:26:05 volumio3 volumio[1017]: info: Received Get System Info May 31 05:26:05 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 05:26:05 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 05:26:05 volumio3 volumio[1017]: info: Discovery: Getting this device information May 31 05:26:05 volumio3 volumio[1017]: info: CoreCommandRouter::volumioGetState May 31 05:26:05 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:26:05 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 05:26:05 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 31 05:26:05 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 31 05:26:05 volumio3 dhcpcd[929]: wlan0: soliciting a DHCP lease May 31 05:26:06 volumio3 volumio5-onboarding[1257]: time=2026-05-31T05:26:06.154Z level=INFO msg="service successfully established" component=discovery/localnet May 31 05:26:06 volumio3 ntpd[799]: Listen normally on 5 wlan1 10.0.1.154:123 May 31 05:26:06 volumio3 ntpd[799]: new interface(s) found: waking up resolver May 31 05:26:10 volumio3 dhcpcd[929]: wlan0: offered 10.0.1.16 from 10.0.1.1 May 31 05:26:10 volumio3 dhcpcd[929]: wlan0: probing for an IPv4LL address May 31 05:26:10 volumio3 dhcpcd[929]: wlan0: probing address 10.0.1.16/24 May 31 05:26:11 volumio3 volumio[1017]: info: Volumio Network Manager: Network status updated: 2 May 31 05:26:11 volumio3 volumio[1017]: info: Discovery: adding 1e572d3e-df44-4883-9262-c0d4e9e5b3b8 May 31 05:26:11 volumio3 volumio[1017]: info: Discovery: Found device Volumio3 May 31 05:26:11 volumio3 volumio[1017]: info: CoreCommandRouter::volumioGetState May 31 05:26:11 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:26:15 volumio3 dhcpcd[929]: wlan0: using IPv4LL address 169.254.138.194 May 31 05:26:15 volumio3 avahi-daemon[535]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.138.194. May 31 05:26:15 volumio3 dhcpcd[929]: wlan0: adding route to 169.254.0.0/16 May 31 05:26:15 volumio3 avahi-daemon[535]: New relevant interface wlan0.IPv4 for mDNS. May 31 05:26:15 volumio3 avahi-daemon[535]: Registering new address record for 169.254.138.194 on wlan0.IPv4. May 31 05:26:15 volumio3 dhcpcd[929]: wlan0: leased 10.0.1.16 for 86400 seconds May 31 05:26:15 volumio3 dhcpcd[929]: wlan0: adding route to 10.0.1.0/24 May 31 05:26:15 volumio3 dhcpcd[929]: wlan0: adding default route via 10.0.1.1 May 31 05:26:15 volumio3 avahi-daemon[535]: Registering new address record for 10.0.1.16 on wlan0.IPv4. May 31 05:26:15 volumio3 dhcpcd[929]: wlan0: deleting route to 169.254.0.0/16 May 31 05:26:15 volumio3 avahi-daemon[535]: Withdrawing address record for 169.254.138.194 on wlan0. May 31 05:26:15 volumio3 avahi-daemon[535]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.138.194. May 31 05:26:15 volumio3 avahi-daemon[535]: Joining mDNS multicast group on interface wlan0.IPv4 with address 10.0.1.16. May 31 05:26:15 volumio3 avahi-daemon[535]: Withdrawing address record for 10.0.1.154 on wlan1. May 31 05:26:15 volumio3 avahi-daemon[535]: Host name conflict, retrying with volumio3-2 May 31 05:26:15 volumio3 avahi-daemon[535]: Registering new address record for 10.0.1.16 on wlan0.IPv4. May 31 05:26:15 volumio3 avahi-daemon[535]: Registering new address record for 10.0.1.154 on wlan1.IPv4. May 31 05:26:15 volumio3 volumio5-onboarding[1257]: time=2026-05-31T05:26:15.635Z level=WARN msg="server name collision detected, resetting service group" component=discovery/localnet May 31 05:26:16 volumio3 volumio[1017]: info: Received Get System Info May 31 05:26:16 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 05:26:16 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 05:26:16 volumio3 volumio[1017]: info: Discovery: Getting this device information May 31 05:26:16 volumio3 volumio[1017]: info: CoreCommandRouter::volumioGetState May 31 05:26:16 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:26:16 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 05:26:16 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 31 05:26:16 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 31 05:26:16 volumio3 volumio[1017]: info: Discovery: A device disappeared from network May 31 05:26:16 volumio3 volumio[1017]: info: Discovery: A device disappeared from network May 31 05:26:17 volumio3 ntpd[799]: Listen normally on 6 wlan0 10.0.1.16:123 May 31 05:26:17 volumio3 ntpd[799]: new interface(s) found: waking up resolver May 31 05:26:17 volumio3 avahi-daemon[535]: Server startup complete. Host name is volumio3-2.local. Local service cookie is 3266883460. May 31 05:26:18 volumio3 avahi-daemon[535]: Service "Volumio3" (/services/volumio.service) successfully established. May 31 05:26:18 volumio3 volumio5-onboarding[1257]: time=2026-05-31T05:26:18.265Z level=INFO msg="service successfully established" component=discovery/localnet May 31 05:26:23 volumio3 volumio[1017]: info: Discovery: adding 1e572d3e-df44-4883-9262-c0d4e9e5b3b8 May 31 05:26:23 volumio3 volumio[1017]: info: Discovery: Found device Volumio3 May 31 05:26:23 volumio3 volumio[1017]: info: CoreCommandRouter::volumioGetState May 31 05:26:23 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:26:23 volumio3 volumio[1017]: info: Discovery: this is already registered, 1e572d3e-df44-4883-9262-c0d4e9e5b3b8 May 31 05:26:23 volumio3 volumio[1017]: info: Discovery: Found device Volumio3 May 31 05:26:23 volumio3 volumio[1017]: info: CoreCommandRouter::volumioGetState May 31 05:26:23 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:26:28 volumio3 wpa_supplicant[898]: wlan0: WPA: Group rekeying completed with 20:c9:d0:a9:b4:32 [GTK=CCMP] May 31 05:26:28 volumio3 volumio[1017]: info: Discovery: this is already registered, 1e572d3e-df44-4883-9262-c0d4e9e5b3b8 May 31 05:26:28 volumio3 volumio[1017]: info: Discovery: Found device Volumio3 May 31 05:26:28 volumio3 volumio[1017]: info: CoreCommandRouter::volumioGetState May 31 05:26:28 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:26:30 volumio3 ntpd[799]: Soliciting pool server 175.210.18.47 May 31 05:26:30 volumio3 ntpd[799]: Soliciting pool server 211.108.117.211 May 31 05:26:35 volumio3 wpa_supplicant[898]: wlan0: WPA: Group rekeying completed with 20:c9:d0:a9:b4:32 [GTK=CCMP] May 31 05:26:41 volumio3 ntpd[799]: Soliciting pool server 240b:400d:3:3300:aeda:71da:9779:d4f1 May 31 05:26:57 volumio3 volumio[1017]: error: error May 31 05:26:57 volumio3 volumio[1017]: error: error May 31 05:26:57 volumio3 volumio[1017]: error: error May 31 05:26:58 volumio3 volumio[1017]: error: error May 31 05:27:01 volumio3 volumio[1017]: error: error May 31 05:27:40 volumio3 volumio[1017]: info: Airplay started streaming, receiving metadatas May 31 05:27:40 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::volumioStop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::stop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 volumio[1017]: info: Airplay started streaming, receiving metadatas May 31 05:27:40 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::volumioStop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::stop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 volumio[1017]: info: Airplay started streaming, receiving metadatas May 31 05:27:40 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::volumioStop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::stop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 shairport-sync[1332]: % Total % Received % Xferd Average Speed Time Time Time Current May 31 05:27:40 volumio3 shairport-sync[1332]: Dload Upload Total Spent Left Speed May 31 05:27:40 volumio3 volumio[1017]: info: Updating volume from AirPlay: -18; 40% May 31 05:27:40 volumio3 volumio[1017]: info: VolumeController::SetAlsaVolume40 May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::pushState May 31 05:27:40 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::volumioPushState May 31 05:27:40 volumio3 volumio[1017]: info: May 31 05:27:40 volumio3 volumio[1017]: ---------------------------- Client requests Start Airplay PlaybackRoutine May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback May 31 05:27:40 volumio3 volumio[1017]: info: Airplay playback start May 31 05:27:40 volumio3 volumio[1017]: info: CorePlayQueue::getTrack 0 May 31 05:27:40 volumio3 volumio[1017]: info: CoreCommandRouter::volumioStop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::stop May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 volumio[1017]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 05:27:40 volumio3 shairport-sync[1332]: [158B blob data] May 31 05:27:40 volumio3 volumio[1017]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'Headphone',0 May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::servicePushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreStateMachine::pushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::volumioPushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::servicePushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreStateMachine::pushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::volumioPushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::servicePushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreStateMachine::pushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::volumioPushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::servicePushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreStateMachine::pushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::volumioPushState May 31 05:27:41 volumio3 volumio[1017]: info: Updating volume from AirPlay: -4.77; 84% May 31 05:27:41 volumio3 volumio[1017]: info: VolumeController::SetAlsaVolume84 May 31 05:27:41 volumio3 volumio[1017]: info: CoreStateMachine::pushState May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 05:27:41 volumio3 volumio[1017]: info: CoreCommandRouter::volumioPushState May 31 05:27:41 volumio3 volumio[1017]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'Headphone',0 May 31 05:27:47 volumio3 ntpd[799]: Soliciting pool server 240b:400d:3:3300:aeda:71da:9779:d8f1 May 31 05:27:50 volumio3 volumio[1017]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 05:27:50 volumio3 volumio[1017]: RangeError [ERR_OUT_OF_RANGE]: The value of "byteLength" is out of range. It must be >= 1 and <= 6. Received 8 May 31 05:27:50 volumio3 volumio[1017]: at boundsError (internal/buffer.js:83:9) May 31 05:27:50 volumio3 volumio[1017]: at Buffer.readUIntBE (internal/buffer.js:270:3) May 31 05:27:50 volumio3 volumio[1017]: at Object.number (/volumio/node_modules/daap-parser/daap-parser.js:33:15) May 31 05:27:50 volumio3 volumio[1017]: at Object.tag [as parseTag] (/volumio/node_modules/daap-parser/daap-parser.js:85:37) May 31 05:27:50 volumio3 volumio[1017]: at ShairportSyncReaderUDP.useData (/volumio/app/plugins/music_service/airplay_emulation/shairport-sync-reader/shairport-sync-reader-base.js:89:38) May 31 05:27:50 volumio3 volumio[1017]: at Socket. (/volumio/app/plugins/music_service/airplay_emulation/shairport-sync-reader/shairport-sync-reader-udp.js:21:12) May 31 05:27:50 volumio3 volumio[1017]: at Socket.emit (events.js:315:20) May 31 05:27:50 volumio3 volumio[1017]: at UDP.onMessage [as onmessage] (dgram.js:919:8) { May 31 05:27:50 volumio3 volumio[1017]: code: 'ERR_OUT_OF_RANGE' May 31 05:27:50 volumio3 volumio[1017]: } May 31 05:27:50 volumio3 volumio[1017]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 05:27:51 volumio3 sudo[3085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-31 05:26 May 31 05:27:51 volumio3 sudo[3085]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"