Airplay audio sound dropping

Volumio version: 2.779
Device: RP3B+
DAC: Abacus AroioDAC (HifiBerry DAC Plus)
Audio Buffer Size 2MB
Buffer before play 10%

Volumio version: 2.779
Device: RP3B
DAC: Innomaker PCM5122 (Allo Boss)
Audio Buffer Size 2MB
Buffer before play 10%

AirPlay coming from iOS version: 13.6 (iPhone X)

When I play music through airplay to both these setups, described above, the sound cuts out after what appears to be a random amount of time. I noticed that once it starts to happen it is then happens sooner the next time. It does not appear to be dependant on the time the device was on, sometimes I can play a few albums other times a couple of songs.

When the sound stops, according to my phone, Apple Music is still playing and AirPlay is still connected. When I connect to Volumio via Volumio app it appears that the song is still playing (the seconds are counting) but there is no sound. Volume is still 100%.

I have not experienced this whilst playing web radio. I do not have a music library so can’t say whether that is affected.

To fix, I disconnect AirPlay and reconnect without stopping the music and the sound returns.

It was happening before I updated to the latest version on both systems.

When I first started using volumio I did not notice this issue. This was around the beginning of July. Not sure what happened since then, maybe Apple updated how Airplay functions and broke shairplay? I have not managed to find any others experiencing this issue (beyond comments about airplay not working at all).

I’m happy to try all troubleshooting tips anyone has. I’m stuck with Apple Music as my wife is 100% apple and uses her watch for music whilst running. We setup a family account and switched from Spotify. I could always start to pay for spotify but it seems a shame to pay twice (for a business model I detest in the first place!).

Here’s what appears in the log when the airplay starts and stops.

Aug 13 15:54:24 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioGetState
Aug 13 15:54:25 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 13 15:54:25 volumio-cyrus volumio[1073]: info: Listing playlists
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 15:54:50 volumio-cyrus shairport-sync[1214]: {"time":1597332767327,"response":"startAirplayPlayback Success"}  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Aug 13 15:54:50 volumio-cyrus shairport-sync[1214]: Dload  Upload   Total   Spent    Left  Speed
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info:
Aug 13 15:54:50 volumio-cyrus volumio[1073]: ---------------------------- Client requests Stop Airplay Playback
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: Airplay playback stop
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: Airplay Playback Stopped, clearing state
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreStateMachine::resetVolumioState
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreStateMachine::getcurrentVolume
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioRetrievevolume
Aug 13 15:54:50 volumio-cyrus shairport-sync[1214]: [155B blob data]
Aug 13 15:54:50 volumio-cyrus volumio[1073]: info: VolumeController:: Volume=100 Mute =false
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreStateMachine::updateTrackBlock
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CorePlayQueue::getTrackBlock
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioRetrievevolume
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: VolumeController:: Volume=100 Mute =false
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 15:54:51 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 15:55:00 volumio-cyrus shairport-sync[1214]: {"time":1597334090916,"response":"stopAirplayPlayback Success"}  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Aug 13 15:55:00 volumio-cyrus shairport-sync[1214]: Dload  Upload   Total   Spent    Left  Speed
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info:
Aug 13 15:55:00 volumio-cyrus volumio[1073]: ---------------------------- Client requests AirplayInactive
Aug 13 15:55:00 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayInctive
Aug 13 15:55:00 volumio-cyrus shairport-sync[1214]: [155B blob data]



Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: Airplay started streaming, receiving metadatas
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: Airplay started streaming, receiving metadatas
Aug 13 15:56:53 volumio-cyrus shairport-sync[1214]: {"time":1597334100921,"response":"airplayInactive Success"}  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Aug 13 15:56:53 volumio-cyrus shairport-sync[1214]: Dload  Upload   Total   Spent    Left  Speed
Aug 13 15:56:53 volumio-cyrus shairport-sync[1214]: 0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Aug 13 15:56:53 volumio-cyrus shairport-sync[1214]: Dload  Upload   Total   Spent    Left  Speed
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info:
Aug 13 15:56:53 volumio-cyrus volumio[1073]: ---------------------------- Client requests AirplayActive
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive
Aug 13 15:56:53 volumio-cyrus shairport-sync[1214]: [155B blob data]
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info:
Aug 13 15:56:53 volumio-cyrus volumio[1073]: ---------------------------- Client requests Start Airplay PlaybackRoutine
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: Airplay playback start
Aug 13 15:56:53 volumio-cyrus shairport-sync[1214]: [136B blob data]
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 15:56:53 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState

Aug 13 16:24:12 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:12 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioGetState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: Listing playlists
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:19 volumio-cyrus shairport-sync[1214]: {"time":1597335630314,"response":"startAirplayPlayback Success"}  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Aug 13 16:24:19 volumio-cyrus shairport-sync[1214]: Dload  Upload   Total   Spent    Left  Speed
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info:
Aug 13 16:24:19 volumio-cyrus volumio[1073]: ---------------------------- Client requests Stop Airplay Playback
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: Airplay playback stop
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: Airplay Playback Stopped, clearing state
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::resetVolumioState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::getcurrentVolume
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioRetrievevolume
Aug 13 16:24:19 volumio-cyrus shairport-sync[1214]: [155B blob data]
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: VolumeController:: Volume=100 Mute =false
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::updateTrackBlock
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CorePlayQueue::getTrackBlock
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioRetrievevolume
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: VolumeController:: Volume=100 Mute =false
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:19 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:20 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioGetState
Aug 13 16:24:21 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 13 16:24:21 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 13 16:24:21 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioGetQueue
Aug 13 16:24:21 volumio-cyrus volumio[1073]: info: CoreStateMachine::getQueue
Aug 13 16:24:21 volumio-cyrus volumio[1073]: info: CorePlayQueue::getQueue
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::servicePushState
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreStateMachine::pushState
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::volumioPushState
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 13 16:24:29 volumio-cyrus shairport-sync[1214]: {"time":1597335859733,"response":"stopAirplayPlayback Success"}  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Aug 13 16:24:29 volumio-cyrus shairport-sync[1214]: Dload  Upload   Total   Spent    Left  Speed
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info:
Aug 13 16:24:29 volumio-cyrus volumio[1073]: ---------------------------- Client requests AirplayInactive
Aug 13 16:24:29 volumio-cyrus shairport-sync[1214]: [155B blob data]
Aug 13 16:24:29 volumio-cyrus volumio[1073]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayInctive

Went for a long walk today and was thinking this must be something to do with either my iPhone or my wifi. Then it dawned on me I’m running NordVPN on my phone. I deactivated it and am now currently testing on the 2nd of the two setups described above. Fingers crossed I’ll get a full evening of uninterrupted listening tonight. Will report back.

[edit: first full evening without losing airplay sound. Will test the other setup for a few hours now. Would be interested in anyones thoughts on whether it could be the VPN that was causing ShairPlay to stop.]