-- Logs begin at Wed 2025-05-21 13:20:40 +03, end at Thu 2025-05-22 09:53:12 +03. -- May 22 09:52:03 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:52:13 biryani-cafe go-librespot[31384]: time="2025-05-22T09:52:13+03:00" level=error msg="did not receive last pong from dealer, 74970s passed" May 22 09:52:14 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 09:52:15 biryani-cafe volumio[1017]: info: Discovery: Getting this device information May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 09:52:15 biryani-cafe volumio[1017]: verbose: New Socket.io Connection to 192.168.1.71 from 192.168.1.30 UA: Mozilla/5.0 (Linux; Android 14; RMX3710 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetVisibleSources May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 09:52:15 biryani-cafe volumio[1017]: info: Received Get System Info May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 09:52:15 biryani-cafe volumio[1017]: info: Discovery: Getting this device information May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:15 biryani-cafe volumio[1017]: info: Listing playlists May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetQueue May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreStateMachine::getQueue May 22 09:52:15 biryani-cafe volumio[1017]: info: CorePlayQueue::getQueue May 22 09:52:15 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 09:52:18 biryani-cafe volumio[1017]: verbose: New Socket.io Connection to 192.168.1.71:3000 from 192.168.1.30 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 May 22 09:52:21 biryani-cafe volumio[1017]: verbose: New Socket.io Connection to 192.168.1.71:3000 from 192.168.1.30 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 May 22 09:52:22 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 09:52:22 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 09:52:22 biryani-cafe volumio[1017]: info: Discovery: Getting this device information May 22 09:52:22 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:22 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 09:52:25 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:52:31 biryani-cafe volumiologrotate[573]: ls: cannot access '/var/log/samba/log.wb-BIRYANI': No such file or directory May 22 09:52:31 biryani-cafe volumiologrotate[573]: ls: cannot access 'CAFE': No such file or directory May 22 09:52:37 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:52:43 biryani-cafe go-librespot[31384]: time="2025-05-22T09:52:43+03:00" level=error msg="did not receive last pong from dealer, 75000s passed" May 22 09:52:48 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:52:48 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 09:52:48 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 09:52:48 biryani-cafe volumio[1017]: info: Discovery: Getting this device information May 22 09:52:48 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:48 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 09:52:50 biryani-cafe shairport-sync[1264]: {"time":1747896424511,"response":"startAirplayPlayback Success"}Very large sync error: 618634 frames, with delay: 706834, td_in_frames: 738870, rt: 4755901102, nt: 4755936291, current_delay: 3153, seqno: 53788, given timestamp: 460968995. May 22 09:52:50 biryani-cafe shairport-sync[1264]: Very large sync error: 618633 frames, with delay: 706833, td_in_frames: 738930, rt: 4755901102, nt: 4755936643, current_delay: 3444, seqno: 53789, given timestamp: 460969347. May 22 09:52:50 biryani-cafe shairport-sync[1264]: Very large sync error: 618632 frames, with delay: 706832, td_in_frames: 738938, rt: 4755901102, nt: 4755936995, current_delay: 3787, seqno: 53790, given timestamp: 460969699. May 22 09:52:50 biryani-cafe shairport-sync[1264]: Very large sync error: 618630 frames, with delay: 706830, td_in_frames: 738941, rt: 4755901102, nt: 4755937347, current_delay: 4134, seqno: 53791, given timestamp: 460970051. May 22 09:52:50 biryani-cafe shairport-sync[1264]: Shome mhistake shurely: very large number of frames to drop: 618630 -- setting it to 132300. May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::servicePushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::servicePushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::servicePushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::servicePushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::servicePushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::servicePushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe shairport-sync[1264]: % Total % Received % Xferd Average Speed Time Time Time Current May 22 09:52:51 biryani-cafe shairport-sync[1264]: Dload Upload Total Spent Left Speed May 22 09:52:51 biryani-cafe volumio[1017]: info: May 22 09:52:51 biryani-cafe volumio[1017]: ---------------------------- Client requests Stop Airplay Playback May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback May 22 09:52:51 biryani-cafe volumio[1017]: info: Airplay playback stop May 22 09:52:51 biryani-cafe volumio[1017]: info: Airplay Playback Stopped, clearing state May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::resetVolumioState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::getcurrentVolume May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioRetrievevolume May 22 09:52:51 biryani-cafe shairport-sync[1264]: [158B blob data] May 22 09:52:51 biryani-cafe volumio[1017]: verbose: New Socket.io Connection to 192.168.1.71:3000 from 192.168.1.30 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 May 22 09:52:51 biryani-cafe volumio[1017]: info: VolumeController:: Volume=88 Mute =false May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::updateTrackBlock May 22 09:52:51 biryani-cafe volumio[1017]: info: CorePlayQueue::getTrackBlock May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioRetrievevolume May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: verbose: New Socket.io Connection to 192.168.1.71 from 192.168.1.30 UA: Mozilla/5.0 (Linux; Android 14; RMX3710 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 09:52:51 biryani-cafe volumio[1017]: info: VolumeController:: Volume=88 Mute =false May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::pushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioPushState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetVisibleSources May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 09:52:51 biryani-cafe volumio[1017]: info: Received Get System Info May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 09:52:51 biryani-cafe volumio[1017]: info: Discovery: Getting this device information May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetState May 22 09:52:51 biryani-cafe volumio[1017]: info: Listing playlists May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::volumioGetQueue May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreStateMachine::getQueue May 22 09:52:51 biryani-cafe volumio[1017]: info: CorePlayQueue::getQueue May 22 09:52:51 biryani-cafe volumio[1017]: SPOTIFY: RECEIVED VOLUMIO VOLUME 88 May 22 09:52:51 biryani-cafe volumio[1017]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 09:52:52 biryani-cafe volumio[1017]: verbose: New Socket.io Connection to 192.168.1.71:3000 from 192.168.1.30 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 May 22 09:52:59 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:53:10 biryani-cafe wpa_supplicant[898]: wlan0: Failed to initiate sched scan May 22 09:53:11 biryani-cafe volumio[1017]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 09:53:11 biryani-cafe volumio[1017]: Error: getaddrinfo ENOTFOUND lastfm.freetls.fastly.net May 22 09:53:11 biryani-cafe volumio[1017]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { May 22 09:53:11 biryani-cafe volumio[1017]: errno: -3007, May 22 09:53:11 biryani-cafe volumio[1017]: code: 'ENOTFOUND', May 22 09:53:11 biryani-cafe volumio[1017]: syscall: 'getaddrinfo', May 22 09:53:11 biryani-cafe volumio[1017]: hostname: 'lastfm.freetls.fastly.net' May 22 09:53:11 biryani-cafe volumio[1017]: } May 22 09:53:11 biryani-cafe volumio[1017]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 09:53:12 biryani-cafe sudo[22345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-22 09:52 May 22 09:53:12 biryani-cafe sudo[22345]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"