mikebrady
commented
5 years ago Thanks for this. Due to work commitments, it will be next week when I can look at this in detail.
Closed joerg-krause closed 3 years ago
mikebrady
commented
5 years ago Thanks for this. Due to work commitments, it will be next week when I can look at this in detail.
mikebrady
commented
5 years ago Just beginning to have a look at this. At approximately 8 milliseconds per frame, it seems that after something around 0.75 seconds, a number of frames are missing and so silent frames are used in place of them. Does it sound plausible that they could really be missing?
joerg-krause
commented
5 years ago I've tested again with the device connected to Ethernet and statistics enabled:
Jun 17 12:25:08 (none) daemon.debug : 1.868374187|prsm
Jun 17 12:25:09 (none) daemon.debug : 0.784150173|Player has supplied a silent frame, (possibly frame 50939) for play number 497.
Jun 17 12:25:09 (none) daemon.debug : 0.001112702|Player has supplied a silent frame, (possibly frame 50940) for play number 498.
Jun 17 12:25:09 (none) daemon.debug : 0.000639687|Player has supplied a silent frame, (possibly frame 50941) for play number 499.
Jun 17 12:25:09 (none) daemon.debug : 0.001527715|Player has supplied a silent frame, (possibly frame 50942) for play number 500.
Jun 17 12:25:09 (none) daemon.debug : 0.040805626|Player has supplied a silent frame, (possibly frame 50943) for play number 501.
Jun 17 12:25:09 (none) daemon.debug : 0.000672355|Player has supplied a silent frame, (possibly frame 50944) for play number 502.
Jun 17 12:25:09 (none) daemon.debug : 0.000810359|Player has supplied a silent frame, (possibly frame 50945) for play number 503.
Jun 17 12:25:09 (none) daemon.debug : 0.000603352|Player has supplied a silent frame, (possibly frame 50946) for play number 504.
Jun 17 12:25:09 (none) daemon.debug : 0.000565685|Player has supplied a silent frame, (possibly frame 50947) for play number 505.
Jun 17 12:25:09 (none) daemon.debug : 0.040057936|Player has supplied a silent frame, (possibly frame 50948) for play number 506.
Jun 17 12:25:09 (none) daemon.debug : 0.000671354|Player has supplied a silent frame, (possibly frame 50949) for play number 507.
Jun 17 12:25:09 (none) daemon.debug : 0.000573018|Player has supplied a silent frame, (possibly frame 50950) for play number 508.
Jun 17 12:25:09 (none) daemon.debug : 0.000546684|Player has supplied a silent frame, (possibly frame 50951) for play number 509.
Jun 17 12:25:09 (none) daemon.debug : 0.000537351|Player has supplied a silent frame, (possibly frame 50952) for play number 510.
Jun 17 12:25:13 (none) daemon.info : 3.960384123| 15.93, 0.0, 0.0, 1003, 14, 157, 0, 157, 8363, 74, 258, 44166.51, 44047.23, 44107.87, 0.00, 0, -1329.55I paused and resumed the playback more than a dozen times in a row. The issue occurs about 50% while this test.
mikebrady
commented
5 years ago Thanks. I guess it's somewhat reassuring that the number of frames missed by Shairport Sync is the same by two different measures. However, I notice that 157 late packets were returned for 157 requests, so it may be that Shairport Sync is not actually asking again for the 14 missing packets in question. I'll have to think about that – it looks like some kind of bug.
mikebrady
commented
5 years ago Hmm, I've neglected this – I'll try to come back to it.
joerg-krause
commented
5 years ago Me too, I'm sticking with version 3.2.2 right now. I'll try to come back to this as soon I have some spare time.
mikebrady
commented
5 years ago Looking at the logic for making a resend request, I am unable to convince myself that it always asks for every missing packet. So I'll take a little time to implement another scheme and come back to you for testing!
mikebrady
commented
5 years ago I have rewritten the missing packet resend requesting logic, and now I can believe in it. If you would be kind enough to try it out whenever you get a chance, it would be great. It seems much better at coping with up to 10% randomly discarded UDP packets. If it does supply a silent frame, it will state how many times it asked for a resend for that packet. The branch is topic/resends, and the version is bumped to 3.3.3d7, up from 3.3.2.d6 which was a mhistake as 3.3.2 is already out.
mikebrady
commented
5 years ago Update — By the way, requests for sequential packets are now consolidated into a single request.
joerg-krause
commented
5 years ago Hi @mikebrady , I finally was able to test the topic/resends branch.
The issue has much improved. Most of the time the playback and resuming playback after a stop works without any problems. Sometimes, I still get the "silent frame" messages:
"player.c:1183" Run a bit past the exact start time by 2100 frames with a DAC delay of 7714 frames.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38622) for play number 14, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38623) for play number 15, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38624) for play number 16, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38625) for play number 17, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38626) for play number 18, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38627) for play number 19, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38628) for play number 20, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38629) for play number 21, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38630) for play number 22, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38631) for play number 23, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38632) for play number 24, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38633) for play number 25, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38634) for play number 26, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38635) for play number 27, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38636) for play number 28, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38637) for play number 29, after 0 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38638) for play number 30, after 1 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38639) for play number 31, after 1 resend requests.
"player.c:1996" Player has supplied a silent frame, (possibly frame 38640) for play number 32, after 1 resend requests.Many thanks! I’ll have a think about this.
mikebrady
commented
5 years ago Hi @joerg-krause. I did find one bug in the code, but can't really imagine how it could have been affecting your situation. Anyway, I have fixed it and have also exposed the settings used in the resend request logic if you wanted to adjust them. They are at the bottom of the general section:
resend_control_first_check_time is the time allowed to elapse before a packet is considered missing, defaulting to 0.1 sec. UDP packets don't always arrive in order and they don't need to be re-requested just because they arrive out of sequence. Essentially, therefore, this parameter is to prevent needless resend requests for packets that are already in transit.resend_control_check_interval_time is the interval between repeated requests for a missing packet, defaulting to 0.25 seconds. resend_control_last_check_time is the time by which the last check should be done before the estimated time of a missing packet's transfer to the output buffer, defaulting to 0.1 seconds. In other words, if a packet is still missing 0.1 seconds before it is due to be transferred to the DAC's output buffer, don't bother asking for a resend.The Player has supplied a silent frame,… message may put out a status, in hexadecimal. Bits 2, 3 and 4 mean that, when the missing packet was last found to be missing, it was either: too late, too early or too soon after the last request, respectively, to send a resend request. Bit 1 means the packet was bad and was discarded.
This update in the development branch – the topic/resends branch is obsolete at present.
Finally, I should have asked, are you using any special settings, particularly in regard to the latency, length of buffers, etc.?
mikebrady
commented
5 years ago The fix is in the master branch now...
github-actions[bot]
commented
3 years ago This issue has been inactive for 60 days so will be closed 7 days from now. To prevent this, please remove the "stale" label or post a comment.
When playing an audio stream from my iPhone device to my embedded Linux board I can hear a small sound distortion shortly after playback has began.
The noise is possibly connected to the following debug message:
Full log:
```txt 0.036588132|Looking for configuration file at full path "/run/shairport-sync/shairport-sync.conf" 0.001481713|Started! 0.000132337|software version: "3.3.1-libdaemon-OpenSSL-Avahi-ALSA-stdout-pipe-metadata-sysconfdir:/etc" 0.000298676|log verbosity is 2. 0.000147005|alsa: init() -- alsa_backend_state => abm_disconnected. 0.000069669|stall_monitor_error_threshold is 0x33333333, with alsa_maximum_stall_time of 0.200000 sec. 0.000314009|Value read for period size is 1920. 0.000069669|Value read for buffer size is 9600. 0.000094670|alsa: disable_standby_mode is "auto". 0.000056668|alsa: output device name is "default". 0.000257008|The processor is running little-endian. 0.000083669|disable resend requests is off. 0.000062002|diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately. 0.000076669|statistics_requester status is 0. 0.000056335|daemon status is 0. 0.000060336|deamon pid file path is "/var/run/shairport-sync.pid". 0.000049668|rtsp listening port is 5000. 0.000046668|udp base port is 6001. 0.000049335|udp port range is 10. 0.000045001|player name is "Wohnzimmer". 0.000049002|backend is "alsa". 0.000047001|run_this_before_play_begins action is "(null)". 0.000070002|run_this_after_play_ends action is "(null)". 0.000069003|wait-cmd status is 1. 0.000045668|run_this_before_play_begins may return output is 0. 0.000052001|run_this_if_an_unfixable_error_is_detected action is "(null)". 0.000061669|run_this_before_entering_active_state action is "(null)". 0.000052335|run_this_after_exiting_active_state action is "(null)". 0.000050335|active_state_timeout is 2.500000 seconds. 0.000053001|mdns backend "(null)". 0.000049002|userSuppliedLatency is 0. 0.000047335|interpolation setting is "basic". 0.000048668|interpolation soxr_delay_threshold is 30. 0.000049001|resync time is 0.050000 seconds. 0.000050335|allow a session to be interrupted: 0. 0.000047668|busy timeout time is 120. 0.000047668|drift tolerance is 0.020000 seconds. 0.000050669|password is "(null)". 0.000044334|ignore_volume_control is 0. 0.000049669|volume_max_db is not set 0.000046668|volume range in dB (zero means use the range specified by the mixer): 0. 0.000062002|volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0. 0.000103336|playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right). 0.000072669|disable_synchronization is 0. 0.000052335|use_mmap_if_available is 1. 0.000047001|output_format automatic selection is enabled. 0.000051669|output_rate automatic selection is enabled. 0.000049001|audio backend desired buffer length is 0.400000 seconds. 0.000051669|audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds. 0.000064668|audio backend latency offset is 0.000000 seconds. 0.000049335|audio backend silence lead-in time is -1.000000 seconds. A value -1.0 means use the default. 0.000064335|zeroconf regtype is "_raop._tcp". 0.000046668|decoders_supported field is 1. 0.000049002|use_apple_decoder is 0. 0.000048001|alsa_use_hardware_mute is 0. 0.000047669|no special mdns service interface was requested. 0.000249007|configuration file name "/run/shairport-sync/shairport-sync.conf" resolves to "/run/shairport-sync/shairport-sync.conf". 0.000101003|metadata enabled is 1. 0.000062336|metadata pipename is "/tmp/shairport-sync-metadata". 0.000060002|metadata socket address is "(null)" port 0. 0.000058335|metadata socket packet size is "500". 0.000051668|get-coverart is 1. 0.332307616|loudness is 0. 0.000185672|loudness reference level is -20.000000 0.000075669|keep_dac_busy is now "no" 0.052638629|avahi: service 'FA9F7342E68D@Wohnzimmer' group is not yet committed. 0.007553900|avahi: request to add "_raop._tcp" service with metadata 0.009716634|avahi: service 'FA9F7342E68D@Wohnzimmer' group is registering. 0.846655864|avahi: service 'FA9F7342E68D@Wohnzimmer' successfully added. 0.785636309|Connection 1: new connection from 192.168.178.113:55527 to self at 192.168.178.116:5000. 0.094201582|Connection 1: Received an RTSP Packet of type "ANNOUNCE": 0.000189339| Type: "Content-Length", content: "646" 0.000086003| Type: "Content-Type", content: "application/sdp" 0.000077335| Type: "CSeq", content: "2" 0.000070002| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000067669| Type: "Active-Remote", content: "3464669148" 0.000073336| Type: "User-Agent", content: "AirPlay/383.1.3" 0.083687923|Play connection from user agent "AirPlay/383.1.3" on RTSP conversation thread 1. 0.000207339|AirPlay version 383 detected. 0.000336344|Connection 1: RTSP Response: 0.000088336| Type: "CSeq", content: "2" 0.000062669| Type: "Server", content: "AirTunes/105.1" 0.020034620|Connection 1: Received an RTSP Packet of type "SETUP": 0.000146004| Type: "Transport", content: "RTP/AVP/UDP;unicast;mode=record;timing_port=55596;control_port=59737" 0.000101670| Type: "CSeq", content: "3" 0.000068336| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000068668| Type: "Active-Remote", content: "3464669148" 0.000068669| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000093336|Connection 1: SETUP -- Active-Remote string seen: "3464669148". 0.000428680|Connection 1: SETUP -- DACP-ID string seen: "4F1BFBBB12D7C889". 0.000752690|Connection 1: SETUP -- Connection from 192.168.178.113 to self at 192.168.178.116. 0.000993364|Connection 1: SETUP DACP-ID "4F1BFBBB12D7C889" from 192.168.178.113 to 192.168.178.116 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003. 0.000154672|Connection 1: RTSP Response: 0.000079669| Type: "CSeq", content: "3" 0.000074336| Type: "Server", content: "AirTunes/105.1" 0.000071002| Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003" 0.000087336| Type: "Session", content: "1" 0.005871515|Connection 1: Received an RTSP Packet of type "RECORD": 0.000138004| Type: "CSeq", content: "4" 0.000080336| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000189006| Type: "Active-Remote", content: "3464669148" 0.000083669| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000096336|Connection 1: RECORD 0.000107004|abeg 0.003995123|keep_dac_busy is now "yes" 0.000173339|alsa: alsa_buffer_monitor_thread_code() calling do_alsa_device_init_if_needed. 0.000110003|alsa: hardware mixer init 0.045608078|*warning: The hardware mixer specified -- "Master" -- does not have a dB volume scale. 0.000890694|alsa: hardware mixer "Master" selected, with dB volume from -51.000000 to 0.000000. 0.047502137|alsa: output format chosen is "S32". 0.029411243|alsa: output speed chosen is 44100. 0.000128004|Attempting to set the period size to 1920 0.027417515|Attempting to set the buffer size to 9600 [AVAudioResampleContext @ 0x148ca90] Value 160.000000 for parameter 'phase_shift' out of range [0 - 30] 0.065425691|PCM handle name = 'default' 0.000159339|alsa device parameters: 0.000062668| access type = MMAP_INTERLEAVED 0.000060669| format = 'S32_LE' (Signed 32 bit Little Endian) 0.000058002| subformat = 'STD' (Standard) 0.000058001| number of channels = 2 0.000055002| number of significant bits = 32 0.000053335| rate = 44100 frames per second (precisely). 0.000052002| precise (rational) rate = 0.000 frames per second (i.e. 0/1088784512). 0.000081002| period_time = 43541 us (>). 0.000055669| period_size = 1920 frames (precisely). 0.000057001| buffer_time = 130612 us (>). 0.000056669| buffer_size = 5760 frames (>). 0.000052335| periods_per_buffer = 2 (>). 0.000078669|alsa: alsa_buffer_monitor_thread_code() -- output device opened; alsa_backend_state => abm_connected 0.000386012|pbeg 0.000269675|Connection 1: RTSP Response: 0.000075669| Type: "CSeq", content: "4" 0.000060002| Type: "Server", content: "AirTunes/105.1" 0.000055335| Type: "Audio-Latency", content: "11025" 0.009918640|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000146671| Type: "Content-Length", content: "18" 0.000062335| Type: "Content-Type", content: "text/parameters" 0.000057669| Type: "CSeq", content: "5" 0.000053002| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000051334| Type: "Active-Remote", content: "3464669148" 0.000050335| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000114004|player_volume_without_notification 0.000000 0.001623050|player_volume_without_notification: volume mode is 1, airplay volume is 0.000000, software_attenuation: 0.000000, hardware_attenuation: 0.000000, muting is disabled. 0.000187006|Connection 1: RTSP Response: 0.000064669| Type: "CSeq", content: "5" 0.000057001| Type: "Server", content: "AirTunes/105.1" 0.016429509|Sync packet received before we got a timing packet back. 0.000231007|Set initial volume to 0.000000. 0.000101336|player_volume_without_notification 0.000000 0.002551079|player_volume_without_notification: volume mode is 1, airplay volume is 0.000000, software_attenuation: 0.000000, hardware_attenuation: 0.000000, muting is disabled. 0.000147005|Play begin 0.074213630|Resend interval for latency of 88200 frames is 31 frames. 0.000323343|Hammerton Decoder used on encrypted audio. 0.006709207|pffr 0.013893097|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000146005| Type: "RTP-Info", content: "rtptime=1261292944" 0.000061668| Type: "Content-Length", content: "66183" 0.000059002| Type: "Content-Type", content: "image/jpeg" 0.000057335| Type: "CSeq", content: "6" 0.000053668| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.001735721| Type: "Active-Remote", content: "3464669148" 0.000111337| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000782024|Connection 1: RTSP Response: 0.000097336| Type: "CSeq", content: "6" 0.000062335| Type: "Server", content: "AirTunes/105.1" 0.001439712|alsa: play() -- alsa_backend_state => abm_playing 0.048604170|Connection 1: Received an RTSP Packet of type "FLUSH": 0.000249008| Type: "RTP-Info", content: "seq=18827;rtptime=1261389124" 0.000160671| Type: "CSeq", content: "7" 0.000137671| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000132005| Type: "Active-Remote", content: "3464669148" 0.000131337| Type: "User-Agent", content: "AirPlay/383.1.3" 0.002068397|pfls 0.000543350|Connection 1: RTSP Response: 0.000182006| Type: "CSeq", content: "7" 0.000144004| Type: "Server", content: "AirTunes/105.1" 0.006736209|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000162672| Type: "RTP-Info", content: "rtptime=1261299287" 0.000080669| Type: "Content-Length", content: "43" 0.000069002| Type: "Content-Type", content: "text/parameters" 0.000069669| Type: "CSeq", content: "8" 0.000070669| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000064002| Type: "Active-Remote", content: "3464669148" 0.000065668| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000156672|Connection 1: RTSP Response: 0.000084336| Type: "CSeq", content: "8" 0.000071335| Type: "Server", content: "AirTunes/105.1" 0.006420866|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000161338| Type: "RTP-Info", content: "rtptime=1261300343" 0.000081336| Type: "Content-Length", content: "174" 0.000073335| Type: "Content-Type", content: "application/x-dmap-tagged" 0.000138005| Type: "CSeq", content: "9" 0.000070335| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000065669| Type: "Active-Remote", content: "3464669148" 0.000068335| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000188006|Connection 1: RTSP Response: 0.000089003| Type: "CSeq", content: "9" 0.000072335| Type: "Server", content: "AirTunes/105.1" 0.006433200|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000160004| Type: "RTP-Info", content: "rtptime=1261300343" 0.000081336| Type: "Content-Length", content: "122" 0.000070669| Type: "Content-Type", content: "application/x-dmap-tagged" 0.000077336| Type: "CSeq", content: "10" 0.000062335| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000063669| Type: "Active-Remote", content: "3464669148" 0.000066002| Type: "User-Agent", content: "AirPlay/383.1.3" 0.001157702|Connection 1: RTSP Response: 0.000118337| Type: "CSeq", content: "10" 0.000078003| Type: "Server", content: "AirTunes/105.1" 0.055643055|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000272008| Type: "RTP-Info", content: "rtptime=1261303511" 0.000155672| Type: "Content-Length", content: "43" 0.000135337| Type: "Content-Type", content: "text/parameters" 0.000141671| Type: "CSeq", content: "11" 0.000123671| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000125337| Type: "Active-Remote", content: "3464669148" 0.000127337| Type: "User-Agent", content: "AirPlay/383.1.3" 0.001743054|Connection 1: RTSP Response: 0.000213340| Type: "CSeq", content: "11" 0.000152672| Type: "Server", content: "AirTunes/105.1" 0.182000631|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000334344| Type: "RTP-Info", content: "rtptime=1261303511" 0.000156338| Type: "Content-Length", content: "66183" 0.000137671| Type: "Content-Type", content: "image/jpeg" 0.000137337| Type: "CSeq", content: "12" 0.000127338| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000129337| Type: "Active-Remote", content: "3464669148" 0.000136338| Type: "User-Agent", content: "AirPlay/383.1.3" 0.001393376|Connection 1: RTSP Response: 0.000203340| Type: "CSeq", content: "12" 0.000153338| Type: "Server", content: "AirTunes/105.1" 0.048902180|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000267675| Type: "RTP-Info", content: "rtptime=1261313719" 0.000154004| Type: "Content-Length", content: "43" 0.000135671| Type: "Content-Type", content: "text/parameters" 0.000132004| Type: "CSeq", content: "13" 0.000123337| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000127338| Type: "Active-Remote", content: "3464669148" 0.000126004| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000857359|Connection 1: RTSP Response: 0.000197340| Type: "CSeq", content: "13" 0.000145338| Type: "Server", content: "AirTunes/105.1" 0.007709238|Connection 1: Received an RTSP Packet of type "SET_PARAMETER": 0.000135004| Type: "RTP-Info", content: "rtptime=1261313719" 0.000062002| Type: "Content-Length", content: "174" 0.000054002| Type: "Content-Type", content: "application/x-dmap-tagged" 0.000064669| Type: "CSeq", content: "14" 0.000053668| Type: "DACP-ID", content: "4F1BFBBB12D7C889" 0.000050335| Type: "Active-Remote", content: "3464669148" 0.000054002| Type: "User-Agent", content: "AirPlay/383.1.3" 0.000219673|Connection 1: RTSP Response: 0.000072002| Type: "CSeq", content: "14" 0.000057669| Type: "Server", content: "AirTunes/105.1" 0.027909863|alsa: flush() -- alsa_backend_state => abm_connected. 0.002877089|pffr 0.014568785|alsa: play() -- alsa_backend_state => abm_playing 1.544867469|prsm 0.783629582|Player has supplied a silent frame, (possibly frame 18943) for play number 98. 0.001407044|Player has supplied a silent frame, (possibly frame 18946) for play number 101. 0.041569286|Player has supplied a silent frame, (possibly frame 18947) for play number 102. 0.000472014|Player has supplied a silent frame, (possibly frame 18948) for play number 103. 0.000357012|Player has supplied a silent frame, (possibly frame 18949) for play number 104. 0.000345677|Player has supplied a silent frame, (possibly frame 18950) for play number 105. 0.002048730|Player has supplied a silent frame, (possibly frame 18951) for play number 106. 0.040343915|Player has supplied a silent frame, (possibly frame 18952) for play number 107. ```
Shairport Sync 3.2.2 works quite well with my setup.