Sync issues / background crackling noise

I'm running shairport-sync on a 528 MHz ARM ultralight processor, with the sound card serial ports using external MCLK crystals. Currently I'm testing with external 22.5792 MHz MCLK and the frame rate is exactly 44100 Hz. But when I play a test sine wave from iTunes running on a Windows 10 PC, I am eventually getting sync errors.

Here is the configuration file: general = { name = "AIRPLAYTEST"; drift_tolerance_in_seconds = 0.5; };

alsa = { output_device = "hw:1"; };

I'm playing directly to the hardware device which natively runs at 44.1 kHz with no mixing, SRC or anything else.

Here is the invocation command:

/tmp/shairport-sync -vv --statistics -u -c /tmp/shairport-sync.conf

And here is the output:

     0.001290666 "shairport.c:459" looking for configuration file at full path "/var/volatile/tmp/shairport-sync.conf"
     0.002249000 "shairport.c:1710" Started!
     0.000936334 "shairport.c:1737" software version: "3.3.7rc2-OpenSSL-tinysvcmdns-ALSA-pa-sysconfdir:/usr/etc"
     0.000486333 "shairport.c:1743" log verbosity is 2.
     0.000806000 "audio_alsa.c:998" alsa: init() -- alsa_backend_state => abm_disconnected.
     0.000541333 "audio_alsa.c:1015" alsa: alsa_maximum_stall_time of 0.200000 sec.
     0.000829000 "audio_alsa.c:1302" alsa: disable_standby_mode is "never".
     0.000681667 "audio_alsa.c:1304" alsa: disable_standby_mode_silence_threshold is 0.040000 seconds.
     0.000494333 "audio_alsa.c:1306" alsa: disable_standby_mode_silence_scan_interval is 0.004000 seconds.
     0.000654334 "audio_alsa.c:1345" alsa: output device name is "hw:1".
     0.000721666 "shairport.c:1758" The processor is running little-endian.
     0.000831667 "shairport.c:1791" disable resend requests is off.
     0.000426333 "shairport.c:1795" diagnostic_drop_packet_fraction is 0.000000. A value of 0.0 means no packets will be dropped deliberately.
     0.000752667 "shairport.c:1796" statistics_requester status is 1.
     0.000395000 "shairport.c:1801" rtsp listening port is 5000.
     0.000766000 "shairport.c:1802" udp base port is 6001.
     0.000387333 "shairport.c:1803" udp port range is 10.
     0.000893334 "shairport.c:1804" player name is "AIRPLAYTEST".
     0.000633333 "shairport.c:1805" backend is "(null)".
     0.000397000 "shairport.c:1806" run_this_before_play_begins action is "(null)".
     0.000354333 "shairport.c:1807" run_this_after_play_ends action is "(null)".
     0.000698334 "shairport.c:1808" wait-cmd status is 0.
     0.000153666 "shairport.c:1809" run_this_before_play_begins may return output is 0.
     0.000103667 "shairport.c:1810" run_this_if_an_unfixable_error_is_detected action is "(null)".
     0.000098667 "shairport.c:1811" run_this_before_entering_active_state action is  "(null)".
     0.000096333 "shairport.c:1812" run_this_after_exiting_active_state action is  "(null)".
     0.000092000 "shairport.c:1813" active_state_timeout is  10.000000 seconds.
     0.000743333 "shairport.c:1814" mdns backend "(null)".
     0.000147000 "shairport.c:1815" userSuppliedLatency is 0.
     0.000104667 "shairport.c:1818" interpolation setting is "basic".
     0.000089667 "shairport.c:1819" interpolation soxr_delay_threshold is 30.
     0.000094666 "shairport.c:1820" resync time is 0.050000 seconds.
     0.000107333 "shairport.c:1821" allow a session to be interrupted: 0.
     0.000131334 "shairport.c:1822" busy timeout time is 120.
     0.000778666 "shairport.c:1823" drift tolerance is 0.500000 seconds.
     0.000182667 "shairport.c:1824" password is "(null)".
     0.000121667 "shairport.c:1825" ignore_volume_control is 0.
     0.000116666 "shairport.c:1829" volume_max_db is not set
     0.000115667 "shairport.c:1831" volume range in dB (zero means use the range specified by the mixer): 0.
     0.000122667 "shairport.c:1835" volume_range_combined_hardware_priority (1 means hardware mixer attenuation is used first) is 0.
     0.000115333 "shairport.c:1837" playback_mode is 0 (0-stereo, 1-mono, 1-reverse_stereo, 2-both_left, 3-both_right).
     0.000793000 "shairport.c:1838" disable_synchronization is 0.
     0.000167667 "shairport.c:1839" use_mmap_if_available is 1.
     0.000127666 "shairport.c:1841" output_format automatic selection is enabled.
     0.000117667 "shairport.c:1845" output_rate automatic selection is enabled.
     0.000112333 "shairport.c:1849" audio backend desired buffer length is 0.200000 seconds.
     0.000146667 "audio_alsa.c:1943" keep_dac_busy is now "no"
     0.000259334 "shairport.c:1851" audio_backend_buffer_interpolation_threshold_in_seconds is 0.120000 seconds.
     0.000803333 "shairport.c:1852" audio backend latency offset is 0.000000 seconds.
     0.000160667 "shairport.c:1854" audio backend silence lead-in time is "auto".
     0.000102666 "shairport.c:1858" zeroconf regtype is "_raop._tcp".
     0.000093667 "shairport.c:1859" decoders_supported field is 1.
     0.000093000 "shairport.c:1860" use_apple_decoder is 0.
     0.000093000 "shairport.c:1861" alsa_use_hardware_mute is 0.
     0.000091000 "shairport.c:1865" no special mdns service interface was requested.
     0.000290333 "shairport.c:1869" configuration file name "/tmp/shairport-sync.conf" resolves to "/var/volatile/tmp/shairport-sync.conf".
     0.000779000 "shairport.c:1898" loudness is 0.
     0.000151334 "shairport.c:1899" loudness reference level is -20.000000

In the configuration file, I have configured a ridiculously high drift tolerance, because I wanted to observe the trend of the sync error without any resync or correction happening. So after running my test for a while, here is how the statistics look like:

     4.522784667 "rtsp.c:2938" Connection 1: new connection from 10.2.1.100:50632 to self at 10.2.1.70:5000.
     0.003268333 "rtsp.c:2621" Connection 1: Received an RTSP Packet of type "ANNOUNCE":
     0.001051334 "rtsp.c:497"   Type: "CSeq", content: "1"
     0.000714333 "rtsp.c:497"   Type: "Content-Type", content: "application/sdp"
     0.001465000 "rtsp.c:497"   Type: "Content-Length", content: "565"
     0.001003667 "rtsp.c:497"   Type: "User-Agent", content: "iTunes/12.10.8 (Windows; Microsoft Windows 10 x64 Professional Edition (Build 19041); x64) (dt:2)"
     0.000784333 "rtsp.c:497"   Type: "Client-Instance", content: "0A93CBB43A98CE0C"
     0.001047000 "rtsp.c:497"   Type: "DACP-ID", content: "0A93CBB43A98CE0C"
     0.001482667 "rtsp.c:497"   Type: "Active-Remote", content: "1673809456"
     0.140281666 "rtsp.c:2184" Play connection from user agent "iTunes/12.10.8 (Windows; Microsoft Windows 10 x64 Professional Edition (Build 19041); x64) (dt:2)" on RTSP conversation thread 1.
     0.001126000 "rtsp.c:2664" Connection 1: RTSP Response:
     0.000405000 "rtsp.c:497"   Type: "CSeq", content: "1"
     0.000660667 "rtsp.c:497"   Type: "Server", content: "AirTunes/105.1"
     0.001046000 "rtsp.c:2621" Connection 1: Received an RTSP Packet of type "SETUP":
     0.000459000 "rtsp.c:497"   Type: "CSeq", content: "2"
     0.000544333 "rtsp.c:497"   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002"
     0.000363000 "rtsp.c:497"   Type: "User-Agent", content: "iTunes/12.10.8 (Windows; Microsoft Windows 10 x64 Professional Edition (Build 19041); x64) (dt:2)"
     0.000303667 "rtsp.c:497"   Type: "Client-Instance", content: "0A93CBB43A98CE0C"
     0.000454000 "rtsp.c:497"   Type: "DACP-ID", content: "0A93CBB43A98CE0C"
     0.000349667 "rtsp.c:497"   Type: "Active-Remote", content: "1673809456"
     0.000303333 "rtsp.c:962" Connection 1: SETUP -- Active-Remote string seen: "1673809456".
     0.000532000 "rtsp.c:977" Connection 1: SETUP -- DACP-ID string seen: "0A93CBB43A98CE0C".
     0.000457000 "rtp.c:963" Connection 1: SETUP -- Connection from 10.2.1.100 to self at 10.2.1.70.
     0.000865000 "rtsp.c:1042" Connection 1: SETUP DACP-ID "0A93CBB43A98CE0C" from 10.2.1.100 to 10.2.1.70 with UDP ports Control: 6001, Timing: 6002 and Audio: 6003.
     0.000448667 "rtsp.c:2664" Connection 1: RTSP Response:
     0.000553000 "rtsp.c:497"   Type: "CSeq", content: "2"
     0.000349333 "rtsp.c:497"   Type: "Server", content: "AirTunes/105.1"
     0.000282333 "rtsp.c:497"   Type: "Transport", content: "RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=6001;timing_port=6002;server_port=6003"
     0.000540667 "rtsp.c:497"   Type: "Session", content: "1"
     0.001200667 "rtsp.c:2621" Connection 1: Received an RTSP Packet of type "RECORD":
     0.000533333 "rtsp.c:497"   Type: "CSeq", content: "3"
     0.000345667 "rtsp.c:497"   Type: "Session", content: "1"
     0.000277333 "rtsp.c:497"   Type: "Range", content: "npt=0-"
     0.000260333 "rtsp.c:497"   Type: "RTP-Info", content: "seq=35743;rtptime=247461769"
     0.000714667 "rtsp.c:497"   Type: "User-Agent", content: "iTunes/12.10.8 (Windows; Microsoft Windows 10 x64 Professional Edition (Build 19041); x64) (dt:2)"
     0.000397333 "rtsp.c:497"   Type: "Client-Instance", content: "0A93CBB43A98CE0C"
     0.000557000 "rtsp.c:497"   Type: "DACP-ID", content: "0A93CBB43A98CE0C"
     0.000331000 "rtsp.c:497"   Type: "Active-Remote", content: "1673809456"
     0.000299667 "rtsp.c:842" Connection 1: RECORD
     0.014720667 "audio_alsa.c:529" alsa: output format chosen is "S32".
     0.000686666 "audio_alsa.c:569" alsa: output speed chosen is 44100.
     0.003458334 "audio_alsa.c:1492" alsa: update timestamps available
     0.000573666 "audio_alsa.c:226" alsa: precision delay timing is available.
     0.000359334 "audio_alsa.c:721" alsa: precision timing selected for "auto" mode
     0.000288333 "audio_alsa.c:738" PCM handle name = 'hw:1'
     0.000496667 "audio_alsa.c:752" alsa device parameters:
     0.000379333 "audio_alsa.c:755"   access type = MMAP_INTERLEAVED
     0.000323000 "audio_alsa.c:759"   format = 'S32_LE' (Signed 32 bit Little Endian)
     0.000576667 "audio_alsa.c:763"   subformat = 'STD' (Standard)
     0.000408333 "audio_alsa.c:766"   number of channels = 2
     0.000424667 "audio_alsa.c:769"   number of significant bits = 32
     0.000509666 "audio_alsa.c:777"   rate = 44100 frames per second (precisely).
     0.000393667 "audio_alsa.c:786"   precise (rational) rate = 0.000 frames per second (i.e. 0/1088784512).
     0.000642333 "audio_alsa.c:799"   period_time = 5804 us (>).
     0.000403667 "audio_alsa.c:809"   period_size = 256 frames (precisely).
     0.000313667 "audio_alsa.c:825"   buffer_time = 185759 us (>).
     0.000528666 "audio_alsa.c:838"   buffer_size = 8192 frames (>).
     0.000485667 "audio_alsa.c:848"   periods_per_buffer = 32 (precisely).
     0.000597000 "audio_alsa.c:1816" alsa: prepare() -- opened output device
     0.000451667 "audio_alsa.c:1965" alsa: alsa_buffer_monitor_thread_code() -- closing the output device
     0.000967000 "player.c:3048" do_flush: flush to 247461769.
     0.000458666 "rtsp.c:2664" Connection 1: RTSP Response:
     0.000736000 "rtsp.c:497"   Type: "CSeq", content: "3"
     0.000356667 "rtsp.c:497"   Type: "Server", content: "AirTunes/105.1"
     0.000106000 "rtsp.c:497"   Type: "Audio-Latency", content: "11025"
     0.001743667 "rtsp.c:2621" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
     0.000139333 "rtsp.c:497"   Type: "CSeq", content: "4"
     0.000049333 "rtsp.c:497"   Type: "Session", content: "1"
     0.000040334 "rtsp.c:497"   Type: "Content-Type", content: "text/parameters"
     0.000039333 "rtsp.c:497"   Type: "Content-Length", content: "18"
     0.000039333 "rtsp.c:497"   Type: "User-Agent", content: "iTunes/12.10.8 (Windows; Microsoft Windows 10 x64 Professional Edition (Build 19041); x64) (dt:2)"
     0.000043667 "rtsp.c:497"   Type: "Client-Instance", content: "0A93CBB43A98CE0C"
     0.000041000 "rtsp.c:497"   Type: "DACP-ID", content: "0A93CBB43A98CE0C"
     0.000040000 "rtsp.c:497"   Type: "Active-Remote", content: "1673809456"
     0.000189333 "loudness.c:47" Volume: 0.0 dB - Loudness gain @10Hz: 0.0 dB
     0.000079334 "player.c:3021" player_volume_without_notification: volume mode is 0, airplay volume is 0.000000, software_attenuation: 0.000000, hardware_attenuation: 0.000000, muting is disabled.
     0.000065666 "rtsp.c:2664" Connection 1: RTSP Response:
     0.000040000 "rtsp.c:497"   Type: "CSeq", content: "4"
     0.000035334 "rtsp.c:497"   Type: "Server", content: "AirTunes/105.1"
     0.001131333 "audio_alsa.c:1754" alsa: do_close() -- closing alsa handle
     0.000270000 "audio_alsa.c:1968" alsa: alsa_buffer_monitor_thread_code() -- alsa_backend_state => abm_disconnected
     0.000982000 "rtsp.c:2621" Connection 1: Received an RTSP Packet of type "SET_PARAMETER":
     0.000440333 "rtsp.c:497"   Type: "CSeq", content: "5"
     0.000457000 "rtsp.c:497"   Type: "Session", content: "1"
     0.000583000 "rtsp.c:497"   Type: "Content-Type", content: "text/parameters"
     0.000135334 "rtsp.c:497"   Type: "Content-Length", content: "18"
     0.000078000 "rtsp.c:497"   Type: "User-Agent", content: "iTunes/12.10.8 (Windows; Microsoft Windows 10 x64 Professional Edition (Build 19041); x64) (dt:2)"
     0.000080666 "rtsp.c:497"   Type: "Client-Instance", content: "0A93CBB43A98CE0C"
     0.000636667 "rtsp.c:497"   Type: "DACP-ID", content: "0A93CBB43A98CE0C"
     0.000304667 "rtsp.c:497"   Type: "Active-Remote", content: "1673809456"
     0.000152666 "loudness.c:47" Volume: 0.0 dB - Loudness gain @10Hz: 0.0 dB
     0.000382667 "player.c:3021" player_volume_without_notification: volume mode is 0, airplay volume is 0.000000, software_attenuation: 0.000000, hardware_attenuation: 0.000000, muting is disabled.
     0.000132333 "rtsp.c:2664" Connection 1: RTSP Response:
     0.000509334 "rtsp.c:497"   Type: "CSeq", content: "5"
     0.000120000 "rtsp.c:497"   Type: "Server", content: "AirTunes/105.1"
     0.004735333 "player.c:1932" sync error in milliseconds, net correction in ppm, corrections in ppm, total packets, missing packets, late packets, too late packets, resend requests, min DAC queue size, min buffer occupancy, max buffer occupancy, source nominal frames per second, source actual frames per second, output frames per second, source clock drift in ppm, source clock drift sample count, rough calculated correction in ppm
     0.001181000 "player.c:1983" Set initial volume to 0.000000.
     0.000494000 "loudness.c:47" Volume: 0.0 dB - Loudness gain @10Hz: 0.0 dB
     0.000870667 "player.c:3021" player_volume_without_notification: volume mode is 0, airplay volume is 0.000000, software_attenuation: 0.000000, hardware_attenuation: 0.000000, muting is disabled.
     0.000692666 "player.c:1986" Play begin
     0.002444334 "player.c:253" Hammerton Decoder used on encrypted audio.
     0.001080000 "player.c:1096" first_packet_time set for frame 247461769.
     0.006364333 "audio_alsa.c:721" alsa: precision timing selected for "auto" mode
     0.000462667 "audio_alsa.c:1780" alsa: play() -- opened output device
     0.000671000 "audio_alsa.c:1785" alsa: play() -- alsa_backend_state => abm_playing
     0.999547000 "player.c:1158" Change in estimated first_packet_time:   0.1022 milliseconds.
     1.010050333 "player.c:1158" Change in estimated first_packet_time:   0.0984 milliseconds.
     0.115547667 "player.c:2262" first frame sync error (positive --> late): -234 frames, -5.306 mS at 44100 frames per second output.
     0.000232333 "player.c:2275" final sync adjustment: 242 silent frames added with a bias of 8 frames.
     7.935039668 "player.c:2747"      -0.09,       0.0,       0.0,        1003,      0,      6,      0,      3,   7944,  257,  260,   44096.51,   44098.90,   44064.44,      0.00,     0,   -727.90
     8.010884001 "player.c:2747"      -0.83,       0.0,       0.0,        2006,      0,      6,      0,      3,   7794,  257,  260,   44096.51,   44096.22,   44083.41,      0.00,     0,   -297.19
     1.926792667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     8002.7,     8218.4,   122833.3.
     6.078155334 "player.c:2747"      -1.57,       0.0,       0.0,        3009,      0,      6,      0,      3,   7944,  257,  259,   44096.51,   44095.27,   44089.52,      0.00,     0,   -158.72
     8.005012667 "player.c:2747"      -2.32,       0.0,       0.0,        4012,      0,      6,      0,      3,   7922,  257,  259,   44096.51,   44096.93,   44092.42,      0.00,     0,    -92.84
     5.872524668 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.9,     6438.2,    23341.0.
     2.132402000 "player.c:2747"      -3.06,       0.0,       0.0,        5015,      0,      6,      0,      3,   7947,  257,  259,   44096.51,   44100.65,   44094.04,      0.00,     0,    -56.10
     8.004987001 "player.c:2747"      -3.80,       0.0,       0.0,        6018,      0,      6,      0,      3,   7949,  257,  259,   44096.51,   44101.81,   44095.19,      0.00,     0,    -30.11
     8.004951001 "player.c:2747"      -4.56,       0.0,       0.0,        7021,      0,      6,      0,      3,   7922,  256,  259,   44096.51,   44100.06,   44096.01,      0.00,     0,    -11.42
     1.830288667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.5,     6412.0,    19518.7.
     6.174552334 "player.c:2747"      -5.30,       0.0,       0.0,        8024,      0,      6,      0,      3,   7762,  257,  259,   44096.51,   44097.08,   44096.59,      0.00,     0,      1.80
     8.005103334 "player.c:2747"      -6.04,       0.0,       0.0,        9027,      0,      6,      0,      3,   7954,  256,  259,   44096.51,   44099.60,   44097.03,      0.00,     0,     11.68
     5.782659001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7984.4,     6344.2,    18786.0.
     2.228120000 "player.c:2747"      -6.80,       0.0,       0.0,       10030,      0,      6,      0,      3,   7949,  256,  259,   44096.51,   44097.70,   44097.39,      0.00,     0,     19.87

As can be seen, the sync error in milliseconds keeps increasing until it hits the 0.05 second limit and then a resync happens. If I configure the drift tolerance to 0.002 (which is the default), the sync correction happens immediately and the sine wave gets noise very shortly. If I set the drift tolerance to 0.01, then it takes a while for the sync correction to happen and during that time, playback is fine.

One thing that strikes me as odd in the statistics is that the reported sample rate of Windows 10 iTunes is 44096.51 (a consistent value). Shouldn't this have been exactly 44100?

I have also tried with MacOs iTunes, and for it, the reported sample rate is also around 44096, but unlike the W10 iTunes, there is very slight variation (less than 1 Hz) with MacOs iTunes.

I have then tried with an iPhone SE, and there, the reported sample rate starts up very close to 44100 and after a while becomes EXACTLY 44100. And also, the sync and noise problem does NOT happen with the iPhone SE for an hour or so, But still, the sync error in millisecond has a very slowly increasing trend.

This is really strange. If the incoming sample rate is different depending on what iTunes is being used, how can shairport-sync work without needing to do continuous sync corrections?

And here are the statistics for the Windows 10 iTunes case, after running for a while. As can be seen, after the sync error hit 0.05 seconds, a resync happened. And also it is evident that the reported sample rate by iTunes is exactly 44096.51, while I was expecting it to be 44100.

     8.010884001 "player.c:2747"      -0.83,       0.0,       0.0,        2006,      0,      6,      0,      3,   7794,  257,  260,   44096.51,   44096.22,   44083.41,      0.00,     0,   -297.19
     1.926792667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     8002.7,     8218.4,   122833.3.
     6.078155334 "player.c:2747"      -1.57,       0.0,       0.0,        3009,      0,      6,      0,      3,   7944,  257,  259,   44096.51,   44095.27,   44089.52,      0.00,     0,   -158.72
     8.005012667 "player.c:2747"      -2.32,       0.0,       0.0,        4012,      0,      6,      0,      3,   7922,  257,  259,   44096.51,   44096.93,   44092.42,      0.00,     0,    -92.84
     5.872524668 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.9,     6438.2,    23341.0.
     2.132402000 "player.c:2747"      -3.06,       0.0,       0.0,        5015,      0,      6,      0,      3,   7947,  257,  259,   44096.51,   44100.65,   44094.04,      0.00,     0,    -56.10
     8.004987001 "player.c:2747"      -3.80,       0.0,       0.0,        6018,      0,      6,      0,      3,   7949,  257,  259,   44096.51,   44101.81,   44095.19,      0.00,     0,    -30.11
     8.004951001 "player.c:2747"      -4.56,       0.0,       0.0,        7021,      0,      6,      0,      3,   7922,  256,  259,   44096.51,   44100.06,   44096.01,      0.00,     0,    -11.42
     1.830288667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.5,     6412.0,    19518.7.
     6.174552334 "player.c:2747"      -5.30,       0.0,       0.0,        8024,      0,      6,      0,      3,   7762,  257,  259,   44096.51,   44097.08,   44096.59,      0.00,     0,      1.80
     8.005103334 "player.c:2747"      -6.04,       0.0,       0.0,        9027,      0,      6,      0,      3,   7954,  256,  259,   44096.51,   44099.60,   44097.03,      0.00,     0,     11.68
     5.782659001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7984.4,     6344.2,    18786.0.
     2.228120000 "player.c:2747"      -6.80,       0.0,       0.0,       10030,      0,      6,      0,      3,   7949,  256,  259,   44096.51,   44097.70,   44097.39,      0.00,     0,     19.87

     8.005030668 "player.c:2747"      -7.53,       0.0,       0.0,       11033,      0,      6,      0,      3,   7954,  256,  259,   44096.51,   44098.23,   44097.71,      0.00,     0,     27.01
     8.004881667 "player.c:2747"      -8.27,       0.0,       0.0,       12036,      0,      6,      0,      3,   7730,  256,  259,   44096.51,   44098.60,   44097.95,      0.00,     0,     32.56
     1.716816334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.9,     6860.5,    19251.0.
     6.288194667 "player.c:2747"      -9.00,       0.0,       0.0,       13039,      0,      6,      0,      3,   7858,  256,  259,   44096.51,   44099.31,   44098.15,      0.00,     0,     37.02
     8.004955335 "player.c:2747"      -9.75,       0.0,       0.0,       14042,      0,      6,      0,      3,   7954,  256,  259,   44096.51,   44099.33,   44097.96,      0.00,     0,     32.79
     5.671665334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7979.8,     7040.5,    16121.7.
     2.333300000 "player.c:2747"     -10.51,       0.0,       0.0,       15045,      0,      6,      0,      3,   7826,  256,  259,   44096.51,   44097.15,   44098.48,      0.00,     0,     44.48
     8.004941334 "player.c:2747"     -11.25,       0.0,       0.0,       16048,      0,      6,      0,      3,   7826,  256,  258,   44096.51,   44096.89,   44098.62,      0.00,     0,     47.71
     8.005038001 "player.c:2747"     -11.99,       0.0,       0.0,       17051,      0,      6,      0,      3,   7954,  256,  258,   44096.51,   44097.38,   44098.62,      0.00,     0,     47.65
     1.621234000 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7979.7,     7043.1,    16829.0.
     6.389500668 "player.c:2747"     -12.74,       0.0,       0.0,       18054,      0,      6,      0,      3,   7794,  256,  259,   44096.51,   44097.50,   44098.84,      0.00,     0,     52.77
     8.004993667 "player.c:2747"     -13.49,       0.0,       0.0,       19057,      0,      6,      0,      3,   7730,  256,  258,   44096.51,   44097.97,   44098.94,      0.00,     0,     54.99
     5.579813668 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.9,     7039.9,    19469.7.
     2.425150667 "player.c:2747"     -14.22,       0.0,       0.0,       20060,      0,      6,      0,      3,   7730,  256,  258,   44096.51,   44096.57,   44099.03,      0.00,     0,     56.99
     8.004949001 "player.c:2747"     -14.84,       0.0,       0.0,       21063,      0,      6,      0,      3,   7794,  256,  258,   44096.51,   44097.50,   44099.10,      0.00,     0,     58.69
     8.004955334 "player.c:2747"     -15.42,       0.0,       0.0,       22066,      0,      6,      0,      3,   7858,  256,  258,   44096.51,   44097.38,   44100.63,      0.00,     0,     93.41
     1.523178333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.0,     7030.4,    16181.0.
     6.481771334 "player.c:2747"     -16.11,       0.0,       0.0,       23069,      0,      6,      0,      3,   7794,  256,  258,   44096.51,   44096.64,   44100.63,      0.00,     0,     93.44
     8.005141001 "player.c:2747"     -16.68,       0.0,       0.0,       24072,      0,      6,      0,      3,   7730,  256,  259,   44096.51,   44098.21,   44099.30,      0.00,     0,     63.10
     5.475974334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7979.4,     7019.7,    16197.0.
     2.529012667 "player.c:2747"     -17.28,       0.0,       0.0,       25075,      0,      6,      0,      3,   7762,  256,  258,   44096.51,   44096.75,   44100.64,      0.00,     0,     93.56
     8.011329335 "player.c:2747"     -17.85,       0.0,       0.0,       26078,      0,      6,      0,      3,   7706,  256,  258,   44096.51,   44096.70,   44100.63,      0.00,     0,     93.43
     8.004233001 "player.c:2747"     -18.33,       0.0,       0.0,       27081,      0,      6,      0,      3,   7515,  256,  258,   44096.51,   44097.57,   44100.64,      0.00,     0,     93.46
     1.427038333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7982.9,     7028.0,    16232.3.
     6.577807668 "player.c:2747"     -18.80,       0.0,       0.0,       28084,      0,      6,      0,      3,   7666,  256,  258,   44096.51,   44097.83,   44100.64,      0.00,     0,     93.59
     8.005287667 "player.c:2747"     -19.23,       0.0,       0.0,       29087,      0,      6,      0,      3,   7442,  256,  258,   44096.51,   44097.87,   44100.62,      0.00,     0,     93.05
     5.370122668 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.9,     7011.3,    17071.3.
     2.634830667 "player.c:2747"     -20.00,       0.0,       0.0,       30090,      0,      6,      0,      3,   7602,  256,  258,   44096.51,   44097.92,   44100.64,      0.00,     0,     93.54
     8.008492667 "player.c:2747"     -20.42,       0.0,       0.0,       31093,      0,      6,      0,      3,   7570,  256,  258,   44096.51,   44097.02,   44100.59,      0.00,     0,     92.52
     8.003239334 "player.c:2747"     -20.90,       0.0,       0.0,       32096,      0,      6,      0,      3,   7538,  256,  258,   44096.51,   44097.56,   44101.40,      0.00,     0,    110.77
     1.318855001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.1,     7008.0,    16075.0.
     6.689321667 "player.c:2747"     -21.54,       0.0,       0.0,       33099,      0,      6,      0,      3,   7506,  256,  258,   44096.51,   44096.91,   44101.29,      0.00,     0,    108.18
     8.007851334 "player.c:2747"     -22.33,       0.0,       0.0,       34102,      0,      6,      0,      3,   7410,  256,  258,   44096.51,   44096.99,   44101.29,      0.00,     0,    108.30
     5.265493334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7979.3,     7008.6,    16544.7.
     2.738414001 "player.c:2747"     -23.10,       0.0,       0.0,       35105,      0,      6,      0,      3,   7442,  256,  258,   44096.51,   44097.07,   44100.78,      0.00,     0,     96.83
     8.007766667 "player.c:2747"     -23.74,       0.0,       0.0,       36108,      0,      6,      0,      3,   7346,  256,  258,   44096.51,   44096.83,   44101.51,      0.00,     0,    113.40
     8.007989001 "player.c:2747"     -24.58,       0.0,       0.0,       37111,      0,      6,      0,      3,   7378,  256,  258,   44096.51,   44096.89,   44101.25,      0.00,     0,    107.49
     1.213568334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7981.3,     7005.5,    16090.0.
     6.791449334 "player.c:2747"     -25.27,       0.0,       0.0,       38114,      0,      6,      0,      3,   7346,  256,  258,   44096.51,   44097.09,   44100.88,      0.00,     0,     98.98
     8.006417667 "player.c:2747"     -26.11,       0.0,       0.0,       39117,      0,      6,      0,      3,   7314,  256,  258,   44096.51,   44097.46,   44101.04,      0.00,     0,    102.54
     5.167710001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.4,     6997.9,    16107.0.
     2.841028000 "player.c:2747"     -26.81,       0.0,       0.0,       40120,      0,      6,      0,      3,   7282,  256,  258,   44096.51,   44096.76,   44100.92,      0.00,     0,     99.93
     8.002122668 "player.c:2747"     -26.12,       0.0,       0.0,       41123,      0,      6,      0,      3,   7250,  256,  258,   44096.51,   44097.24,   44100.92,      0.00,     1,     99.82
     8.004795668 "player.c:2747"     -26.65,       0.0,       0.0,       42126,      0,      6,      0,      3,   7282,  256,  258,   44096.51,   44096.80,   44100.65,      0.00,     1,     93.70
     1.116726666 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7979.4,     7006.5,    16472.3.
     6.893725335 "player.c:2747"     -27.44,       0.0,       0.0,       43129,      0,      6,      0,      3,   7250,  256,  258,   44096.51,   44096.72,   44100.66,      0.00,     1,     93.96
     8.002191001 "player.c:2747"     -28.21,       0.0,       0.0,       44132,      0,      6,      0,      3,   7218,  256,  258,   44096.51,   44096.82,   44101.22,      0.00,     1,    106.79
     5.061997333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7977.3,     7013.0,    18697.0.
     2.946366667 "player.c:2747"     -28.94,       0.0,       0.0,       45135,      0,      6,      0,      3,   7058,  256,  259,   44096.51,   44097.25,   44100.70,      0.00,     2,     94.86
     8.005184001 "player.c:2747"     -29.60,       0.0,       0.0,       46138,      0,      6,      0,      3,   6994,  256,  258,   44096.51,   44096.75,   44101.16,      0.00,     2,    105.41
     8.008668668 "player.c:2747"     -30.27,       0.0,       0.0,       47141,      0,      6,      0,      3,   7122,  256,  258,   44096.51,   44097.11,   44100.91,      0.00,     4,     99.72
     1.016917334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7985.2,     7001.6,    16196.7.
     6.986343000 "player.c:2747"     -31.02,       0.0,       0.0,       48144,      0,      6,      0,      3,   6890,  256,  258,   44096.51,   44096.77,   44100.97,      0.00,     4,    101.01
     8.007605668 "player.c:2747"     -31.80,       0.0,       0.0,       49147,      0,      6,      0,      3,   7026,  256,  258,   44096.51,   44097.31,   44100.95,      0.00,     4,    100.58
     4.962216334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7982.1,     7004.9,    19224.0.
     3.042686334 "player.c:2747"     -32.49,       0.0,       0.0,       50150,      0,      6,      0,      3,   6834,  256,  258,   44096.51,   44097.29,   44101.10,      0.00,     4,    104.03
     8.008988001 "player.c:2747"     -33.27,       0.0,       0.0,       51153,      0,      6,      0,      3,   6994,  256,  258,   44096.51,   44097.19,   44100.71,      0.00,     5,     95.09
     8.004340334 "player.c:2747"     -33.75,       0.0,       0.0,       52156,      0,      6,      0,      3,   6994,  256,  258,   44096.51,   44096.79,   44100.68,      0.00,     6,     94.36
     0.902803667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7977.7,     6995.1,    16065.7.
     7.105442667 "player.c:2747"     -34.58,       0.0,       0.0,       53159,      0,      6,      0,      3,   6930,  256,  258,   44096.51,   44096.97,   44101.13,      0.00,     7,    104.73
     8.004038001 "player.c:2747"     -35.18,       0.0,       0.0,       54162,      0,      6,      0,      3,   6898,  256,  258,   44096.51,   44096.85,   44100.96,      0.00,     7,    100.82
     4.862689001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.1,     7006.2,    16102.7.
     3.144563333 "player.c:2747"     -35.87,       0.0,       0.0,       55165,      0,      6,      0,      3,   6866,  256,  258,   44096.51,   44097.13,   44100.78,      0.00,     8,     96.76
     8.009701668 "player.c:2747"     -36.63,       0.0,       0.0,       56168,      0,      6,      0,      3,   6642,  256,  258,   44096.51,   44096.77,   44101.04,      0.00,     8,    102.68
     8.002147668 "player.c:2747"     -37.29,       0.0,       0.0,       57171,      0,      6,      0,      3,   6834,  256,  258,   44096.51,   44096.84,   44100.89,      5.94,     9,     93.29
     0.799973333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7981.8,     7003.0,    16200.0.
     7.210832668 "player.c:2747"     -38.02,       0.0,       0.0,       58174,      0,      6,      0,      3,   6766,  256,  258,   44096.51,   44096.76,   44100.72,      5.84,    10,     89.62
     8.005373001 "player.c:2747"     -38.66,       0.0,       0.0,       59177,      0,      6,      0,      3,   6765,  256,  258,   44096.51,   44097.27,   44101.02,      5.84,    10,     96.26
     4.751434667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7981.3,     7003.3,    16046.3.
     3.253539000 "player.c:2747"     -39.45,       0.0,       0.0,       60180,      0,      6,      0,      3,   6738,  256,  258,   44096.51,   44096.98,   44100.74,      5.84,    10,     90.05
     8.005691001 "player.c:2747"     -40.14,       0.0,       0.0,       61183,      0,      6,      0,      3,   6610,  256,  258,   44096.51,   44097.23,   44101.11,      5.84,    10,     98.30
     8.007858668 "player.c:2747"     -40.74,       0.0,       0.0,       62186,      0,      6,      0,      3,   6514,  256,  258,   44096.51,   44096.90,   44100.69,      5.84,    10,     88.83
     0.698513000 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.5,     7007.2,    17770.7.
     7.306238001 "player.c:2747"     -41.50,       0.0,       0.0,       63189,      0,      6,      0,      3,   6638,  256,  258,   44096.51,   44097.04,   44100.98,      5.86,    11,     95.44
     8.007686001 "player.c:2747"     -42.25,       0.0,       0.0,       64192,      0,      6,      0,      3,   6610,  256,  258,   44096.51,   44097.32,   44100.76,      5.86,    11,     90.37
     4.652473334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7980.8,     7003.7,    16168.3.
     3.352783667 "player.c:2747"     -42.92,       0.0,       0.0,       65195,      0,      6,      0,      3,   6546,  256,  258,   44096.51,   44097.19,   44100.71,      5.86,    11,     89.23
     8.007052334 "player.c:2747"     -43.63,       0.0,       0.0,       66198,      0,      6,      0,      3,   6418,  256,  258,   44096.51,   44097.13,   44100.79,      5.97,    12,     91.05
     8.006430667 "player.c:2747"     -44.25,       0.0,       0.0,       67201,      0,      6,      0,      3,   6514,  256,  258,   44096.51,   44097.33,   44101.02,      5.97,    12,     96.24
     0.601784001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7986.4,     7011.3,    16176.7.
     7.407075000 "player.c:2747"     -44.97,       0.0,       0.0,       68204,      0,      6,      0,      3,   6450,  256,  258,   44096.51,   44096.76,   44101.01,      6.14,    14,     95.77
     8.001929668 "player.c:2747"     -45.62,       0.0,       0.0,       69207,      0,      6,      0,      3,   6450,  256,  258,   44096.51,   44096.83,   44100.88,      6.14,    14,     92.97
     4.554206334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7984.9,     6992.9,    16176.0.
     3.452444667 "player.c:2747"     -46.37,       0.0,       0.0,       70210,      0,      6,      0,      3,   6226,  256,  258,   44096.51,   44097.28,   44100.79,      6.10,    15,     90.91
     8.007665334 "player.c:2747"     -46.95,       0.0,       0.0,       71213,      0,      6,      0,      3,   6354,  256,  258,   44096.51,   44097.15,   44100.75,      6.10,    15,     90.06
     8.005033668 "player.c:2747"     -47.73,       0.0,       0.0,       72216,      0,      6,      0,      3,   6322,  256,  258,   44096.51,   44097.08,   44100.98,      6.10,    15,     95.20
     0.498325333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7985.0,     7002.5,    16400.7.
     7.512155668 "player.c:2747"     -48.50,       0.0,       0.0,       73219,      0,      6,      0,      3,   6322,  256,  258,   44096.51,   44096.77,   44100.74,      6.16,    16,     89.56
     3.918932334 "player.c:2333" Large negative sync error: -2286 with should_be_frame_32 of 273498307, nt of 273407337 and current_delay of 6322.
     0.004487000 "player.c:2345" Play a silence of 2286 frames.
     0.076972333 "player.c:2164" Player: packets out of sequence: expected: 43917, got: 43926, with ab_read: 43927 and ab_write: 44185.
     4.016741667 "player.c:2747"     -28.33,       0.0,       0.0,       74222,      0,      6,      0,      3,   6318,  256,  259,   44096.51,   43672.46,   44100.65,      6.17,    18,     87.55
     4.435730001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7985.6,     7019.8,    19610.0.
     3.569370667 "player.c:2747"      -8.35,       0.0,       0.0,       75225,      0,      6,      0,      3,   7808,  256,  259,   44096.51,   44080.73,   44100.59,      6.16,    19,     86.31
     8.004975001 "player.c:2747"      -9.06,       0.0,       0.0,       76228,      0,      6,      0,      3,   7808,  256,  259,   44096.51,   44087.28,   44100.64,      6.16,    19,     87.31
     8.005012667 "player.c:2747"      -9.75,       0.0,       0.0,       77231,      0,      6,      0,      3,   7936,  256,  259,   44096.51,   44098.42,   44100.63,      6.17,    20,     87.26

During the above test, the shairport-sync and the windows 10 PC were connected over an 100Base-T ethernet with maximum thoughput as measured with iperf3.

The CPU load on the ARM processor where shairport-sync is running never exceeds 20%.

Thanks for the posts. Let's take them one at a time:

With basic interpolation you will hear crackling on a pure tone like a sine wave. It's much harder to hear in normal audio. With soxr interpolation, you'll still hear something faintly on a pure tone, but it is really almost completely inaudible on regular audio such as music or speech. If you set interpolation to "auto", you'll get soxr interpolation if the CPU is fast enough. It needs to have good floating point performance. For reference, Raspberry Pi's are generally okay from the Pi Zero up, but they have pretty fancy FPUs.
Looking at the three frame rate figures in the statistics output, the first one is based on what effectively seems to be the rate at which the source "intends" to output the audio, and that rate is generally 44,096.51 from iTunes and macOS Music and, more or less, 44,100 for all other sources. The number 44,096.51 is not a measured value -- it's calculated from the data sent by the source. It's very peculiar -- more later. The second frame rate number is an attempt to estimate the true frame rate of incoming audio based on the number of packets of audio received over time. Its accuracy is susceptible to network errors. Over a long (hours) period on a very clean network, it should be accurate. The third figure is based on the number of frames send to the DAC, averaged over time. So long as the DAC is not suffering underrun, this will be as accurate as the clock on the system can manage. If the clock is conditioned by NTP, then I believe that, over time, it is extremely accurate.
Shairport Sync works by by monitoring the size of a buffer of audio frames that is supplied by the source and drained by the output device. If the buffer grows, then interpolation will reduce the number of incoming frames by removing one occasionally ("basic") or by merging some occasionally ("soxr"). If the buffer shrinks, interpolation will add a frame occasionally. Shairport Sync doesn't do any so-to-speak "theoretical" calculations to do its interpolation. It does, however, use linear regression to get a better fix on the drift between the clocks of the source device and the output device -- regression is applied after enough reliable timing messages have been exchanged, which can take a minute or so. Once calculated, Shairport Sync stores the calculated drift so that the next time that source is used, the stored drift is used until a newly calculated drift can be used. It seems to work well and is stable, and seems to come up with sensible values. If you imagine a crystal-controlled oscillator with an accuracy of half a second per day, that's around 15 ppm, so you could expect to see drifts between two devices of up to around 30 ppm on occasion and, statistically, it would be very likely that the drifts would be a lot less. This is certainly what I see. In your last log, you can see a drift of around 6.1 ppm, which seems plausible.

Returning to the 44,096.51 FPS phenomenon, it's a real puzzle, and I've spent lots of time trying to understand it. In particular, adding those three frame-rate numbers, flawed as they may be, to the statistics log was part of it. It is so hard to believe that Apple -- of all companies -- would be doing something so flagrantly incorrect. Therefore, I'm inclined to think that -- just maybe -- we don't have a full picture of the AirPlay protocol. Is it possible, for instance, that real Apple AirPlay devices are sending back some kind of servo information to moderate the output rate very slightly? Unfortunately, I have seen absolutely nothing about this anywhere. I also have not tried to sniff any sessions -- my expertise in that area is low.

So I guess the occasional crackling as a result of bit stuffing or removal is to be expected. But during my testing, that's not the only thing that's happening.

Here is another test I did with W10 iTunes playing a sinewave. The drift tolerance is set to 0.01 s. As can be seen, audio plays fine, with no correction until the 0.01 s mark is hit. Once the 0.01 s mark is hit, shairport-sync is in a mode where it does continuous correction, with a continuous stream of crackling sounds heard indefinitely. Shouldn't be the normal behavior to make an ajustment at the 0.01 s mark, with a few crackling sounds, but then clean audio playback until the drift hits 0.01 s again?

     0.000710000 "player.c:1986" Play begin
     0.004225334 "player.c:253" Hammerton Decoder used on encrypted audio.
     0.001073000 "player.c:1096" first_packet_time set for frame 2647157141.
     0.006529000 "audio_alsa.c:721" alsa: precision timing selected for "auto" mode
     0.000639666 "audio_alsa.c:1780" alsa: play() -- opened output device
     0.000367667 "audio_alsa.c:1785" alsa: play() -- alsa_backend_state => abm_playing
     0.893915667 "player.c:1158" Change in estimated first_packet_time:   0.0615 milliseconds.
     0.121432333 "player.c:1158" Change in estimated first_packet_time:   0.1022 milliseconds.
     0.779346000 "player.c:1158" Change in estimated first_packet_time:  -0.0241 milliseconds.
     0.230731334 "player.c:1158" Change in estimated first_packet_time:   0.0984 milliseconds.
     0.105782666 "player.c:2262" first frame sync error (positive --> late): -7 frames, -0.159 mS at 44100 frames per second output.
     0.000196000 "player.c:2275" final sync adjustment: 15 silent frames added with a bias of 8 frames.
     7.929224001 "player.c:2747"      -0.09,       0.0,       0.0,        1003,      0,      8,      0,      5,   7856,  257,  260,   44096.51,   44149.69,   44100.68,      0.00,     0,     94.47
     8.010912335 "player.c:2747"      -0.61,       0.0,       0.0,        2006,      0,      8,      0,      5,   7949,  257,  260,   44096.51,   44125.62,   44100.69,      0.00,     0,     94.70
     1.936869333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     8006.8,     8050.1,    48328.0.
     6.068063334 "player.c:2747"      -1.36,       0.0,       0.0,        3009,      0,      8,      0,      5,   7958,  257,  260,   44096.51,   44112.09,   44100.41,      0.00,     0,     88.33
     8.004875335 "player.c:2747"      -2.09,       0.0,       0.0,        4012,      0,      8,      0,      5,   7960,  257,  259,   44096.51,   44104.67,   44100.46,      0.00,     0,     89.48
     5.898432334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.0,     6723.9,    16766.7.
     2.106521000 "player.c:2747"      -2.87,       0.0,       0.0,        5015,      0,      8,      0,      5,   7960,  257,  259,   44096.51,   44107.47,   44100.63,      0.00,     0,     93.33
     8.005109334 "player.c:2747"      -3.64,       0.0,       0.0,        6018,      0,      8,      0,      5,   7960,  257,  259,   44096.51,   44106.61,   44100.62,      0.00,     0,     93.22
     8.004985668 "player.c:2747"      -4.39,       0.0,       0.0,        7021,      0,      8,      0,      5,   7960,  257,  259,   44096.51,   44100.20,   44100.60,      0.00,     0,     92.70
     1.848249000 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7985.4,     6669.8,    16131.7.
     6.156690001 "player.c:2747"      -5.16,       0.0,       0.0,        8024,      0,      8,      0,      5,   7956,  257,  259,   44096.51,   44105.12,   44100.56,      0.00,     0,     91.67
     8.004857667 "player.c:2747"      -5.90,       0.0,       0.0,        9027,      0,      8,      0,      5,   7955,  256,  259,   44096.51,   44095.99,   44100.61,      0.00,     0,     92.83
     5.798560668 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7983.0,     6592.7,    16644.7.
     2.212174000 "player.c:2747"      -6.61,       0.0,       0.0,       10030,      0,      8,      0,      5,   7960,  256,  259,   44096.51,   44103.42,   44100.61,      0.00,     1,     92.91
     8.004961668 "player.c:2747"      -6.72,       0.0,       0.0,       11033,      0,      8,      0,      5,   7950,  256,  259,   44096.51,   44102.64,   44100.57,      0.00,     2,     91.96
     8.004962334 "player.c:2747"      -7.61,       0.0,       0.0,       12036,      0,      8,      0,      5,   7950,  256,  259,   44096.51,   44102.26,   44100.61,      0.00,     3,     92.97
     1.742186333 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7984.2,     6576.6,    16800.0.
     6.262911001 "player.c:2747"      -8.56,       0.0,       0.0,       13039,      0,      8,      0,      5,   7957,  256,  259,   44096.51,   44100.82,   44100.57,      0.00,     4,     92.01
     8.005014334 "player.c:2747"      -9.25,       0.0,       0.0,       14042,      0,      8,      0,      5,   7960,  256,  259,   44096.51,   44099.05,   44100.56,      0.00,     5,     91.75
     5.695490668 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7984.8,     6558.6,    17198.0.
     2.309335333 "player.c:2747"      -9.92,      17.0,      17.0,       15045,      0,      8,      0,      5,   7951,  256,  258,   44096.51,   44100.62,   44100.60,      0.00,     6,     92.73
     8.005085335 "player.c:2747"     -10.27,      70.8,      70.8,       16048,      0,      8,      0,      5,   7937,  256,  258,   44096.51,   44099.56,   44100.58,      0.00,     6,     92.29
     8.010780667 "player.c:2747"     -10.29,      93.5,      93.5,       17051,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44099.44,   44098.70,      0.00,     6,     49.48
     1.643105334 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7986.8,     6818.9,    16237.0.
     6.361878667 "player.c:2747"     -10.31,      87.8,      87.8,       18054,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44099.00,   44098.80,      0.00,     6,     51.90
     8.004976335 "player.c:2747"     -10.29,      82.1,      82.1,       19057,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44099.16,   44098.90,      0.00,     6,     54.14
     5.588528000 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7981.8,     7037.8,    16132.7.
     2.416422334 "player.c:2747"     -10.29,      73.6,      73.6,       20060,      0,      8,      0,      5,   7917,  256,  259,   44096.51,   44099.46,   44100.58,      0.00,     7,     92.26
     8.010802001 "player.c:2747"     -10.28,      96.3,      96.3,       21063,      0,      8,      0,      5,   7892,  256,  259,   44096.51,   44100.00,   44100.59,      0.00,     8,     92.50
     8.005018334 "player.c:2747"     -10.22,      85.0,      85.0,       22066,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44098.17,   44100.59,      4.32,     9,     88.18
     1.535950000 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7981.5,     7028.9,    16136.0.
     6.468944334 "player.c:2747"     -10.30,      73.6,      73.6,       23069,      0,      8,      0,      5,   7902,  256,  259,   44096.51,   44098.74,   44100.59,      4.53,    10,     87.86
     8.005108001 "player.c:2747"     -10.31,      99.1,      99.1,       24072,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44099.55,   44100.59,      4.73,    11,     87.64
     5.494687001 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7987.1,     7021.3,    16258.3.
     2.515935667 "player.c:2747"     -10.29,      87.8,      87.8,       25075,      0,      8,      0,      5,   7907,  256,  259,   44096.51,   44099.02,   44099.31,      4.82,    12,     58.63
     8.005027668 "player.c:2747"     -10.28,      76.5,      76.5,       26078,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44098.63,   44099.36,      4.88,    13,     59.59
     8.005047334 "player.c:2747"     -10.26,      90.6,      90.6,       27081,      0,      8,      0,      5,   7883,  256,  259,   44096.51,   44098.84,   44099.40,      4.93,    14,     60.58
     1.434785667 "rtp.c:138" Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds:     7984.0,     7014.3,    16066.3.
     6.570051000 "player.c:2747"     -10.28,      85.0,      85.0,       28084,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44098.23,   44100.59,      4.97,    15,     87.50
     8.010730335 "player.c:2747"     -10.27,      96.3,      96.3,       29087,      0,      8,      0,      5,   7937,  256,  259,   44096.51,   44098.93,   44100.59,      4.97,    15,     87.54

I guess you could imagine making a big adjustment when it drifts outside the sync tolerance, but IMHO that would be very disruptive -- you'd be chopping or inserting a few milliseconds of audio from time to time, and that would be very audible. Instead, Shairport Sync does as little as possible to stay within the bounds (e.g. ± 2 milliseconds). That means that when it reaches a bound it will make small continuous adjustments.

Returning to the 44,096.51 FPS phenomenon, it's a real puzzle, and I've spent lots of time trying to understand it. In particular, adding those three frame-rate numbers, flawed as they may be, to the statistics log was part of it. It is so hard to believe that Apple -- of all companies -- would be doing something so flagrantly incorrect. Therefore, I'm inclined to think that -- just maybe -- we don't have a full picture of the AirPlay protocol. Is it possible, for instance, that real Apple AirPlay devices are sending back some kind of servo information to moderate the output rate very slightly? Unfortunately, I have seen absolutely nothing about this anywhere. I also have not tried to sniff any sessions -- my expertise in that area is low.

Just following up on this. Monitoring the traffic between a genuine Airport Express (Second Generation) and macOS Music on an iMac, the calculation give 44,096.514 fps over a period of about an hour.

I have now run shairport-sync on my Debian Linux desktop system, with "soxr" interpolation. As with the "basic" interpolation, after a while, shairport-sync starts doing continuous sync correction and there is the slight crackling noise. Audibly, both the "soxr" and "basic" crackling sounds very similar to me.

I have also tried playing from the same Windows 10 iTunes to a Marantz SR7011, which has AirPlay support. Playing the same sine tone. The output stays clean even after about a half hour.

So what could be the difference with the SR7011? I'm wondering whether the SR7011 is using a frequency modulated clock that can be slightly adjusted to always stay in sync with the source ... It doesn't seem likely to me that the SR7011 is doing any bit stuffing, because that would definitely show up as a THD+N spike (I'm monitoring the audio output using an Audio Precision AP525 audio analyzer that does continuous FFT and THD+N measurement)

Thanks. I'm afraid don't know what the Marantz is doing -- is it even using AirPlay or is it actually AirPlay 2 (it seems to be AirPlay 2 compatible)? Not too much is known about AirPlay 2, but it seems to use the PTP precision timing protocol and so it may be that the Matantz can lock clocks with iTunes.

[Update] Nice gear, BTW, as is the Audio Precision AP525.

One question: Given that the Windows 10 and MacOS iTunes is sending at exactly the 44096.51 Hz rate, can I possibly use an asynchronous sample rate conversion library to convert that rate to 44100? It seems to me that this would eliminate the need for bit stuffing and would yield clean output. What do you think?

At this point, I just want shairport-sync to work with a single speaker (not paired with other speakers). I want to address the syncing of multiple speakers later on.

I think the ALSA system has built-in rate converters; they might be worth trying.

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.

mikebrady / shairport-sync

Sync issues / background crackling noise #1070