can't play from allstream on android: 'packets out of sequence', 'Error -32 in delay(): "Broken pipe"'

[jordanade]

When I try to connect and play from allstream, I get no audio--except every several seconds, there's a tiny chirp of the audio that comes through. Here's a -vvv output:

===== here I run shairport-sync -a test -vvv ======

Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 0. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "1". resync time is 2205. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 88 frames. password is "(null)". ignore_volume_control is 0. disable_synchronization is 0. audio backend desired buffer length is 6615. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2".

===== Here I connect allstream =====

New RTSP connection on port 5000 Client-Instance: B370A9CB22EED3A7. DACP-ID: B370A9CB22EED3A7. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: B370A9CB22EED3A7. DACP-ID: B370A9CB22EED3A7. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: B370A9CB22EED3A7. DACP-ID: B370A9CB22EED3A7. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=35083;timing_port=37051. DACP-ID string seen: "B370A9CB22EED3A7". rtp_setup: cport=35083 tport=37051. Connection from IPv4: 10.0.0.20:38631 listening for audio, control and timing on ports 6001, 6002, 6003. Timing receiver -- Server RTP thread starting. Audio receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: B370A9CB22EED3A7. DACP-ID: B370A9CB22EED3A7. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=51128;rtptime=1102327727. Range: npt=0-. Flush requested up to 1102327726. It seems as if 0 is special. Client-Instance: B370A9CB22EED3A7. DACP-ID: B370A9CB22EED3A7. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 13. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: 0.000000

syncing to seqno 51129. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely). Aliasing of buffer index -- reset. Aliasing of buffer index -- reset.

===== Here I start playing audio =====

Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 51136, got: 52672, with ab_read: 52673 and ab_write: 53174. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: -6142. Flush requested up to 1102872271. It seems as if 0 is special. syncing to seqno 53174. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7969.4, 26579.3, 162093.0. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7970.5, 26672.1, 152755.0. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7966.8, 26777.7, 200336.0. Player: packets out of sequence: expected: 57786, got: 58298, with ab_read: 58299 and ab_write: 58805. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: -6218. Flush requested up to 1104852623. It seems as if 0 is special. syncing to seqno 58805. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8006.7, 26928.4, 254060.0. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 62394, got: 62906, with ab_read: 62907 and ab_write: 63409. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: -6533. Flush requested up to 1106473583. It seems as if 0 is special. syncing to seqno 63409. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7965.7, 26523.7, 164601.0.

===== end of log ======

I also emailed allstream about this, their address is allstream@kineticgamestudios.com

Thanks, Jordanade

[mikebrady]

Thanks for the report. This is a problem that's ongoing – see #217 and #21. I don't have an android device that I can "root", so I'm afraid I can't test AllStream. Could you check with an iOS or iTunes source, just to see if the installation and network is okay?

[jordanade]

Yes, iTunes/11.3.1/Mac plays fine to Shairport-Sync, and Allstream plays fine to my Airport Express. I just have a problem with Allstream to Shairport-Sync.

[mikebrady]

Thanks for the update.

[mikebrady]

Just as an experiment, could you turn off synchronisation (in the alsa section of /etc/shairport-sync.conf, set disable_synchronization = "yes") and turn on statistics (in the general section, set statistics = "yes"), and let's see what happens?

[jordanade]

OK, here goes. Same results--a tiny bit of audio every minute or so.

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "1". resync time is 2205. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 88 frames. password is "(null)". ignore_volume_control is 0. disable_synchronization is 1. audio backend desired buffer length is 6615. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2".

===== Here I connect allstream =====

New RTSP connection on port 5000 Client-Instance: F7EF67178E966380. DACP-ID: F7EF67178E966380. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: F7EF67178E966380. DACP-ID: F7EF67178E966380. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: F7EF67178E966380. DACP-ID: F7EF67178E966380. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=40995;timing_port=48775. DACP-ID string seen: "F7EF67178E966380". rtp_setup: cport=40995 tport=48775. Connection from IPv4: 10.0.0.20:46169 listening for audio, control and timing on ports 6001, 6002, 6003. Audio receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Timing receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: F7EF67178E966380. DACP-ID: F7EF67178E966380. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=57763;rtptime=-5553511104533197313. Range: npt=0-. Flush requested up to 4263284222. It seems as if 0 is special. Client-Instance: F7EF67178E966380. DACP-ID: F7EF67178E966380. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 13. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: 0.000000

syncing to seqno 57764. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely). Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 57783, got: 59319, with ab_read: 59320 and ab_write: 59824. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7975.3, 26642.9, 141788.0. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 59321, got: 60345, with ab_read: 60346 and ab_write: 60851. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7975.4, 27457.9, 156943.0. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 60347, got: 62907, with ab_read: 62908 and ab_write: 63415. Aliasing of buffer index -- reset.

===== Here I begin playing audio =====

Player: packets out of sequence: expected: 62909, got: 63421, with ab_read: 63422 and ab_write: 63929. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7964.9, 27100.2, 150638.0. Player: packets out of sequence: expected: 63424, got: 64960, with ab_read: 64961 and ab_write: 65468. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 64965, got: 965, with ab_read: 966 and ab_write: 1472. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 writing 352 samples in play(): "Broken pipe". Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8011.3, 26976.4, 153633.0. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 972, got: 2508, with ab_read: 2509 and ab_write: 3012. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 2510, got: 4046, with ab_read: 4047 and ab_write: 4551. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 writing 352 samples in play(): "Broken pipe". Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7958.3, 26957.2, 184855.0. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8015.1, 27084.2, 151056.0. Player: packets out of sequence: expected: 4066, got: 7138, with ab_read: 7139 and ab_write: 7644. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 7144, got: 8168, with ab_read: 8169 and ab_write: 8671. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7956.5, 26781.2, 164939.0. Player: packets out of sequence: expected: 8170, got: 9706, with ab_read: 9707 and ab_write: 10217. Aliasing of buffer index -- reset. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 9707, got: 10731, with ab_read: 10732 and ab_write: 11237. Aliasing of buffer index -- reset. Player: packets out of sequence: expected: 10732, got: 11244, with ab_read: 11245 and ab_write: 11749. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Aliasing of buffer index -- reset. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8015.6, 27007.1, 230980.0. Aliasing of buffer index -- reset.

.....etc.....

[jordanade]

Was there an additional log created by statistics = "yes"? I don't see anything different...

[mikebrady]

Many thanks for all your efforts. The statistics log would appear in line with the log above, but it looks as if it didn't get a chance. There is a possibility, I guess, that AllStream uses a long latency. Shairport Sync has 512 buffers (approximately 710 kB altogether), so is good for a latency of about 4 seconds. If the latency used by AllStream is longer than that, it would account for the aliasing. If you were willing, I could modify Shairport Sync to have 1024 buffers (approximately 1420 kB altogether). You'd have to download, recompile and reinstall, but at least we could see if it's something like that. Would you be willing to try it out? BTW, I have also written to AllStream.

[mikebrady]

As a matter of interest, what system and DAC are you running?

[jordanade]

I had to compile to install the version I'm using now, so it seems simple enough to do that. Just let me know what to do.

The equipment is an Asus Chromebox, and I'm using the built-in headphone jack exclusively for Shairport-Sync. (The other software on the machine outputs to the HDMI port.)

On Thu, Apr 28, 2016, 6:08 AM Mike Brady notifications@github.com wrote:

As a matter of interest, what system and DAC are you running?

— You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub https://github.com/mikebrady/shairport-sync/issues/279#issuecomment-215376338

[mikebrady]

Thanks. I've push a new branch called, imaginatively, longer_buffer. So, if you could follow the directions for updating but, after where is says $git pull enter git checkout longer_buffer and then do another git pull and continue with the directions, it should build a special version of Shairport Sync with 1024 buffers rather than 512. This should definitively put to rest the question of whether AllStream is using a very long latency...

[jordanade]

With longer_buffer, the audio plays in much longer chunks--about 1-3 seconds at a time, and much more frequently, every 1-3 seconds. This is with disable_synchronization = "no".

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3.1-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "0". resync time is 2205. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 88 frames. password is "(null)". ignore_volume_control is 0. mono is 0. disable_synchronization is 0. audio backend desired buffer length is 6615. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". metadata socket address is "(null)" port 0. metadata socket packet size is "500". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2".

===== Here I connect allstream =====

New RTSP connection on port 5000 Client-Instance: B55B022E1B2810C3. DACP-ID: B55B022E1B2810C3. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: B55B022E1B2810C3. DACP-ID: B55B022E1B2810C3. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: B55B022E1B2810C3. DACP-ID: B55B022E1B2810C3. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=59588;timing_port=48775. DACP-ID string seen: "B55B022E1B2810C3". rtp_setup: cport=59588 tport=48775. Connection from IPv4: 10.0.0.20:49238 listening for audio, control and timing on ports 6001, 6002, 6003. Audio receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Timing receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: B55B022E1B2810C3. DACP-ID: B55B022E1B2810C3. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=60504;rtptime=15419103. Range: npt=0-. Flush requested up to 15419102. It seems as if 0 is special. Client-Instance: B55B022E1B2810C3. DACP-ID: B55B022E1B2810C3. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 13. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: 0.000000

Using negotiated latency of 187425 frames. syncing to seqno 60505. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely). Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: -3105. Flush requested up to 15595807. It seems as if 0 is special. syncing to seqno 61524. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.1, 26438.1, 139503.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: -3349. Flush requested up to 16217087. It seems as if 0 is special. syncing to seqno 63291. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7970.9, 26697.7, 149523.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2758. Flush requested up to 17053791. It seems as if 0 is special. syncing to seqno 136. Sync error: -542.5 (frames); net correction: 150.6 (ppm); corrections: 491.5 (ppm); total packets 3758; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 2894, min and max buffer occupancy 498 and 527. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2740. Flush requested up to 17364959. It seems as if 0 is special. syncing to seqno 1018. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2533. Flush requested up to 17631071. It seems as if 0 is special. syncing to seqno 1774. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7954.5, 26982.8, 200484.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3930. Flush requested up to 17896479. It seems as if 0 is special. syncing to seqno 2529. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2929. Flush requested up to 18163295. It seems as if 0 is special. syncing to seqno 3286. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3406. Flush requested up to 18429407. It seems as if 0 is special. syncing to seqno 4041. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3095. Flush requested up to 18738815. It seems as if 0 is special. syncing to seqno 4925. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8013.2, 27736.8, 155797.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2709. Flush requested up to 19005983. It seems as if 0 is special. syncing to seqno 5679. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2930. Flush requested up to 19272799. It seems as if 0 is special. syncing to seqno 6436. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3635. Flush requested up to 19538207. It seems as if 0 is special. syncing to seqno 7192. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7962.6, 26919.2, 162553.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2433. Flush requested up to 19849023. It seems as if 0 is special. syncing to seqno 8076. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3238. Flush requested up to 20114079. It seems as if 0 is special. syncing to seqno 8830. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3592. Flush requested up to 20380191. It seems as if 0 is special. syncing to seqno 9586. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8011.7, 27551.9, 168254.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3150. Flush requested up to 20646655. It seems as if 0 is special. syncing to seqno 10342. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2970. Flush requested up to 20913471. It seems as if 0 is special. syncing to seqno 11097. Sync error: -466.7 (frames); net correction: 28.7 (ppm); corrections: 163.3 (ppm); total packets 7516; missing packets 0; late packets 4; too late packets 0; resend requests 0; min DAC queue size 4253, min and max buffer occupancy 502 and 529. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 4416. Flush requested up to 21222175. It seems as if 0 is special. syncing to seqno 11979. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7968.1, 27244.3, 134774.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 4474. Flush requested up to 21490399. It seems as if 0 is special. syncing to seqno 12737. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 4473. Flush requested up to 21755455. It seems as if 0 is special. syncing to seqno 13492. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8008.5, 27150.3, 148631.0. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2885. Flush requested up to 22332735. It seems as if 0 is special. syncing to seqno 15130. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 3042. Flush requested up to 22863903. It seems as if 0 is special. syncing to seqno 16642. Lost sync with source for 4 consecutive packets -- flushing and resyncing. Error: 2925. Flush requested up to 23130719. It seems as if 0 is special. syncing to seqno 17398. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7955.6, 26244.2, 161316.0. ^Cshutdown requested... avahi: avahi_unregister. Request to shut down all rtsp conversation threads asking playing threads to stop RTSP shutdown requested. Closing down RTSP conversation thread... Playback Stopped. Total playing time 00:03:09

[jordanade]

With longer_buffer AND disable_synchronization = "yes", audio plays without problems--or mostly, at least--there was at least one very brief dropout but I think it was a CPU thing with the phone. Nice...

There is a about a 4-second latency between playing audio on Allstream and hearing it on the receiver, because that's what I set in AllStream: http://imgbox.com/e1Igv9uk I set it back to what I think the default was, 2.0 seconds, and it didn't seem to make any difference in terms of using synchronization successfully.

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3.1-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "0". resync time is 2205. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 88 frames. password is "(null)". ignore_volume_control is 0. mono is 0. disable_synchronization is 1. audio backend desired buffer length is 6615. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". metadata socket address is "(null)" port 0. metadata socket packet size is "500". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2".

=== connect allstream ===

New RTSP connection on port 5000 Client-Instance: AC861F83CDD1CCC4. DACP-ID: AC861F83CDD1CCC4. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: AC861F83CDD1CCC4. DACP-ID: AC861F83CDD1CCC4. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 569. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: AC861F83CDD1CCC4. DACP-ID: AC861F83CDD1CCC4. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=33009;timing_port=48775. DACP-ID string seen: "AC861F83CDD1CCC4". rtp_setup: cport=33009 tport=48775. Connection from IPv4: 10.0.0.20:49300 listening for audio, control and timing on ports 6001, 6002, 6003. Audio receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Timing receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: AC861F83CDD1CCC4. DACP-ID: AC861F83CDD1CCC4. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=63717;rtptime=39618751. Range: npt=0-. Flush requested up to 39618750. It seems as if 0 is special. Client-Instance: AC861F83CDD1CCC4. DACP-ID: AC861F83CDD1CCC4. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 13. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: 0.000000

Using negotiated latency of 187425 frames. syncing to seqno 63718. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely).

=== begin playing audio ===

Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7969.3, 23964.8, 177675.0. Synchronisation disabled. Sync error: -1730.0 (frames); total packets 3758; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 2125, min and max buffer occupancy 496 and 526. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7972.5, 25847.4, 138446.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.2, 26540.2, 145421.0. Synchronisation disabled. Sync error: -2051.9 (frames); total packets 7516; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 2096, min and max buffer occupancy 498 and 527. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8006.8, 26658.9, 146481.0. Synchronisation disabled. Sync error: -2196.4 (frames); total packets 11274; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 1163, min and max buffer occupancy 498 and 529. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7963.0, 26631.1, 156721.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8015.9, 26895.9, 149060.0. Synchronisation disabled. Sync error: -2300.3 (frames); total packets 15032; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 1342, min and max buffer occupancy 496 and 528. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7959.7, 26769.9, 152873.0. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 writing 352 samples in play(): "Broken pipe". Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Error -32 in delay(): "Broken pipe". Delay reported is 0 frames. Delay error -32 when checking running latency. Synchronisation disabled. Sync error: -86.6 (frames); total packets 18790; missing packets 0; late packets 3; too late packets 0; resend requests 0; min DAC queue size 0, min and max buffer occupancy 479 and 550. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8011.2, 27279.8, 302612.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.3, 26733.6, 148776.0. Synchronisation disabled. Sync error: 4018.8 (frames); total packets 22548; missing packets 0; late packets 3; too late packets 0; resend requests 0; min DAC queue size 7520, min and max buffer occupancy 499 and 528. Client-Instance: AC861F83CDD1CCC4. DACP-ID: AC861F83CDD1CCC4. CSeq: 5. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTSP shutdown requested. Closing down RTSP conversation thread... Playback Stopped. Total playing time 00:03:17

=== disconnect allstream ===

Shut down audio, control and timing threads Control RTP thread interrupted. terminating. Timing thread interrupted. terminating. rtp_timing_sender thread interrupted. terminating. Audio receiver -- Server RTP thread interrupted. terminating. Closed and terminated timer requester thread. Timing RTP thread terminated. timing thread joined audio thread joined control thread joined Player thread exit shutting down RTP thread RTSP conversation thread terminated.

=== kill shairport-sync ===

^Cshutdown requested... avahi: avahi_unregister. Request to shut down all rtsp conversation threads asking playing threads to stop

[jordanade]

In this latter config I've been listening to music for an hour now without problems or gaps. Playing from allstream to both shairport-sync and an airport express simultaneously, the audio is mostly in sync...after an hour maybe 30-40ms apart. Not ideal but sort of works.

[jordanade]

Would you be able to increase the buffer by even more, so that synchronization can be turned back on? Or is there a better solution, perhaps on the allstream side?

[mikebrady]

Thanks for the update – it seems we're making progress. I got a reply from AllStream and I'll draw their attention to this thread. Setting the delay to 4 seconds was that cause of those "Aliasing of buffer index -- reset.". By default, Shairport Sync has space for 512 packets, each of which is 7,981.86 microseconds long, thus 4.09 seconds – too close to fours seconds for any comfort. So, if it makes no other difference, set the latency to 2 seconds.

I'm going to make a few guesses now to see if we can get synchronisation working. I'm guessing that the timing information coming from AllStream isn't as stable over the short term as what would come from iTunes or iOS, so I'll make a few suggestions to try to accommodate it:

1. Turn synchronisation back on by commenting out the disable_synchronisation = "yes"; setting.
2. Disable resynchronisation by setting the resync_threshold in the general section to 0. Don't forget to uncomment it.
3. Set the drift setting in the general section to, say, 1100. Don't forget to uncomment it.
4. Set the audio_backend_buffer_desired_length in the alsa section of the settings to, say, 22050. Don't forget to uncomment it.

Restart Shairport Sync. These settings should make Shairport Sync more tolerant of short-term inaccuracies in the clocking information and allow a little more time before the DAC would run out of samples.

[jordanade]

Ah yes, ironically I had earlier increased the delay because I thought it would help. I've tried your suggested settings, and it seems that they work pretty well. The stats still suggest a very wide range of packet reception intervals, and there are still very occasional and very brief drop-outs, perhaps a 100ms or 200ms gap every 5 to 10 minutes, but it's pretty minor and the overall performance is pretty good, with apparently perfect synchronization... Anyhow, your software is great. Thanks for your efforts on this project and your help on this issue. Here's the log:

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3.1-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "1". resync time is 0. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 1100 frames. password is "(null)". ignore_volume_control is 0. mono is 0. disable_synchronization is 0. audio backend desired buffer length is 22050. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". metadata socket address is "(null)" port 0. metadata socket packet size is "500". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2".

=== connected allstream ===

New RTSP connection on port 5000 Client-Instance: 6D8F96F28D20720B. DACP-ID: 6D8F96F28D20720B. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: 6D8F96F28D20720B. DACP-ID: 6D8F96F28D20720B. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: 6D8F96F28D20720B. DACP-ID: 6D8F96F28D20720B. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=57119;timing_port=50082. DACP-ID string seen: "6D8F96F28D20720B". rtp_setup: cport=57119 tport=50082. Connection from IPv4: 10.0.0.20:54320 listening for audio, control and timing on ports 6001, 6002, 6003. Audio receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Timing receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: 6D8F96F28D20720B. DACP-ID: 6D8F96F28D20720B. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=1408;rtptime=-7536358543797588814. Range: npt=0-. Flush requested up to 1895230641. It seems as if 0 is special. Client-Instance: 6D8F96F28D20720B. DACP-ID: 6D8F96F28D20720B. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 13. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: 0.000000

Using negotiated latency of 99225 frames. syncing to seqno 1409. The alsa buffer is to small (16384 bytes) to accommodate the desired backend buffer length (22050) you have chosen. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely).

=== start playing audio ===

Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.4, 27792.1, 171304.0. Sync error: 1266.0 (frames); net correction: -341.1 (ppm); corrections: 471.7 (ppm); total packets 3758; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 4624, min and max buffer occupancy 221 and 276. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7982.5, 27717.6, 199168.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7952.7, 27888.6, 154576.0. Sync error: 339.3 (frames); net correction: -311.5 (ppm); corrections: 1575.4 (ppm); total packets 7516; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 13481, min and max buffer occupancy 221 and 249. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8011.2, 27913.2, 136190.0. Sync error: 112.6 (frames); net correction: -215.4 (ppm); corrections: 1444.6 (ppm); total packets 11274; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 14129, min and max buffer occupancy 221 and 247. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.0, 27834.2, 182042.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8016.5, 26146.9, 141824.0. Sync error: -195.8 (frames); net correction: 321.3 (ppm); corrections: 1246.6 (ppm); total packets 15032; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 14688, min and max buffer occupancy 221 and 245. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7956.2, 25194.2, 144195.0. Sync error: -165.6 (frames); net correction: 121.7 (ppm); corrections: 1677.5 (ppm); total packets 18790; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 13567, min and max buffer occupancy 225 and 248. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8012.9, 25581.0, 153072.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.5, 25646.7, 201126.0. Sync error: -102.8 (frames); net correction: -56.7 (ppm); corrections: 1552.0 (ppm); total packets 22548; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 14435, min and max buffer occupancy 215 and 246. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8009.8, 25428.1, 146638.0. Sync error: -139.9 (frames); net correction: 76.4 (ppm); corrections: 1562.6 (ppm); total packets 26306; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 14925, min and max buffer occupancy 225 and 245. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7958.0, 25495.5, 148308.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7974.1, 25639.8, 146619.0. Sync error: 28.8 (frames); net correction: 18.9 (ppm); corrections: 1236.0 (ppm); total packets 30064; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 14503, min and max buffer occupancy 224 and 245. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.1, 25278.0, 152150.0. Sync error: -3.8 (frames); net correction: -36.3 (ppm); corrections: 1359.2 (ppm); total packets 33822; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 14361, min and max buffer occupancy 225 and 246. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7979.1, 25459.1, 138735.0.

[mikebrady]

Thanks. It's getting better alright. I'd suggest the audio_backend_buffer_desired_length in the alsa section of the settings back down to, say, 11025. That should (!) give us a pretty good idea of how things stand.

[jordanade]

Similar results. A sub-second drop-out every 10 minutes or so.

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3.1-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "1". resync time is 0. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 1100 frames. password is "(null)". ignore_volume_control is 0. mono is 0. disable_synchronization is 0. audio backend desired buffer length is 11025. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". metadata socket address is "(null)" port 0. metadata socket packet size is "500". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2".

New RTSP connection on port 5000 Client-Instance: DF7657C1FD98014F. DACP-ID: DF7657C1FD98014F. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: DF7657C1FD98014F. DACP-ID: DF7657C1FD98014F. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: DF7657C1FD98014F. DACP-ID: DF7657C1FD98014F. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=39260;timing_port=50082. DACP-ID string seen: "DF7657C1FD98014F". rtp_setup: cport=39260 tport=50082. Connection from IPv4: 10.0.0.20:55638 listening for audio, control and timing on ports 6001, 6002, 6003. Audio receiver -- Server RTP thread starting. Timing receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: DF7657C1FD98014F. DACP-ID: DF7657C1FD98014F. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=43809;rtptime=3455756818. Range: npt=0-. Flush requested up to 3455756817. It seems as if 0 is special. Client-Instance: DF7657C1FD98014F. DACP-ID: DF7657C1FD98014F. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 13. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: 0.000000

Using negotiated latency of 99225 frames. syncing to seqno 43810. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely). Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7963.9, 26109.0, 226971.0. Sync error: 1634.3 (frames); net correction: -496.8 (ppm); corrections: 496.8 (ppm); total packets 3758; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 4437, min and max buffer occupancy 231 and 276. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7985.3, 25448.1, 153643.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7964.4, 25658.2, 183651.0. Sync error: 439.3 (frames); net correction: -407.5 (ppm); corrections: 1072.7 (ppm); total packets 7516; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8030, min and max buffer occupancy 230 and 267. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7998.0, 25538.4, 153339.0. Sync error: -14.4 (frames); net correction: -117.2 (ppm); corrections: 1201.2 (ppm); total packets 11274; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7810, min and max buffer occupancy 234 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7965.6, 26047.3, 178594.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8005.9, 25571.2, 185375.0. Sync error: -107.1 (frames); net correction: 59.0 (ppm); corrections: 1192.9 (ppm); total packets 15032; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 4985, min and max buffer occupancy 211 and 275. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.5, 24829.9, 138017.0. Sync error: 28.9 (frames); net correction: -81.6 (ppm); corrections: 1478.7 (ppm); total packets 18790; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8322, min and max buffer occupancy 225 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8008.5, 25592.8, 149624.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.5, 25560.0, 144408.0. Sync error: 117.1 (frames); net correction: -6.8 (ppm); corrections: 1219.4 (ppm); total packets 22548; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7882, min and max buffer occupancy 234 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8008.1, 25369.9, 138690.0. Sync error: 39.5 (frames); net correction: -55.9 (ppm); corrections: 1335.0 (ppm); total packets 26306; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7703, min and max buffer occupancy 235 and 266. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7968.0, 25511.8, 140085.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7965.2, 25355.4, 141220.0. Sync error: 43.1 (frames); net correction: 99.0 (ppm); corrections: 1387.2 (ppm); total packets 30064; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7237, min and max buffer occupancy 235 and 266. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7966.8, 25359.5, 144912.0. Sync error: 19.1 (frames); net correction: -15.9 (ppm); corrections: 1477.9 (ppm); total packets 33822; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8557, min and max buffer occupancy 230 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.8, 25141.3, 176343.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8000.6, 25242.3, 146415.0. Sync error: -62.4 (frames); net correction: 277.4 (ppm); corrections: 1494.5 (ppm); total packets 37580; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8199, min and max buffer occupancy 235 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7968.0, 25536.0, 155544.0. Sync error: 114.8 (frames); net correction: -161.0 (ppm); corrections: 1360.0 (ppm); total packets 41338; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7797, min and max buffer occupancy 235 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8005.6, 25152.8, 155920.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7966.9, 23793.6, 149951.0. Sync error: 79.6 (frames); net correction: -133.8 (ppm); corrections: 1379.6 (ppm); total packets 45096; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8339, min and max buffer occupancy 215 and 266. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8003.2, 25700.8, 155473.0. Sync error: -134.5 (frames); net correction: 71.8 (ppm); corrections: 1325.2 (ppm); total packets 48854; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7046, min and max buffer occupancy 236 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7969.8, 25348.8, 143516.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8002.4, 25441.3, 145595.0. Sync error: 34.9 (frames); net correction: 49.9 (ppm); corrections: 1341.1 (ppm); total packets 52612; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8031, min and max buffer occupancy 235 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7968.4, 25571.5, 142376.0. Sync error: -20.5 (frames); net correction: -33.3 (ppm); corrections: 1267.0 (ppm); total packets 56370; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7976, min and max buffer occupancy 232 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7974.4, 25551.9, 144671.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7992.2, 25405.9, 156337.0. Sync error: 11.5 (frames); net correction: -110.4 (ppm); corrections: 1330.5 (ppm); total packets 60128; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7712, min and max buffer occupancy 236 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7974.9, 25489.6, 147765.0. Sync error: -193.6 (frames); net correction: 183.7 (ppm); corrections: 1304.0 (ppm); total packets 63886; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7992, min and max buffer occupancy 236 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8007.0, 25831.0, 182570.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7971.0, 25335.4, 131815.0. Sync error: 32.6 (frames); net correction: -16.6 (ppm); corrections: 1608.7 (ppm); total packets 67644; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7927, min and max buffer occupancy 234 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7998.5, 25614.8, 156003.0. Sync error: 39.8 (frames); net correction: -28.7 (ppm); corrections: 1598.1 (ppm); total packets 71402; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8145, min and max buffer occupancy 234 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7969.0, 25715.2, 151456.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7999.8, 25599.3, 164733.0. Sync error: 20.2 (frames); net correction: -7.6 (ppm); corrections: 1484.7 (ppm); total packets 75160; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7306, min and max buffer occupancy 231 and 269. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7973.2, 25117.9, 140627.0. Sync error: 12.9 (frames); net correction: -204.1 (ppm); corrections: 1471.1 (ppm); total packets 78918; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8102, min and max buffer occupancy 235 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.5, 25583.3, 142926.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.7, 24855.7, 168554.0.

[mikebrady]

Thanks again. It looks like there's a wide spectrum of instantaneous sync error values, causing a great deal of over-correction, e.g. net correction: -7.6 (ppm); corrections: 1484.7. It would be worth widening the drift tolerance so that the ratio of corrections to the absolute value of net corrections came down – normally it's pretty close to 1:1. Whenever you might have the chance, try a drift value of 5000 and see what happens.

[mikebrady]

I'm going to delete the longer_buffer branch in the next short while, if that's okay. The nearest equivalent is the development branch.

[jordanade]

I don't hear any gaps anymore, although the sync with my airport express now seems to be loose enough to create an obvious reverberation effect in my apartment.

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3.1-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "1". resync time is 0. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 5000 frames. password is "(null)". ignore_volume_control is 0. mono is 0. disable_synchronization is 0. audio backend desired buffer length is 11025. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". metadata socket address is "(null)" port 0. metadata socket packet size is "500". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2". New RTSP connection on port 5000 Client-Instance: F126A5BC6B075321. DACP-ID: F126A5BC6B075321. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: F126A5BC6B075321. DACP-ID: F126A5BC6B075321. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: F126A5BC6B075321. DACP-ID: F126A5BC6B075321. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=43996;timing_port=32985. DACP-ID string seen: "F126A5BC6B075321". rtp_setup: cport=43996 tport=32985. Connection from IPv4: 10.0.0.20:60643 listening for audio, control and timing on ports 6001, 6002, 6003. Timing receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Audio receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: F126A5BC6B075321. DACP-ID: F126A5BC6B075321. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=7991;rtptime=1053535765. Range: npt=0-. Flush requested up to 1053535764. It seems as if 0 is special. Client-Instance: F126A5BC6B075321. DACP-ID: F126A5BC6B075321. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 15. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: -3.300000

Using negotiated latency of 99225 frames. syncing to seqno 7992. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely). Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.2, 26389.6, 175264.0. Sync error: 2091.7 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 3758; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 4408, min and max buffer occupancy 234 and 276. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7974.1, 26505.4, 199030.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7957.6, 26790.8, 138208.0. Sync error: 2259.4 (frames); net correction: -44.6 (ppm); corrections: 44.6 (ppm); total packets 7516; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 10581, min and max buffer occupancy 235 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8017.2, 25801.5, 146857.0. Sync error: 1935.7 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 11274; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 10131, min and max buffer occupancy 231 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7972.4, 25522.9, 178637.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8004.0, 25443.1, 136685.0. Sync error: 1675.9 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 15032; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9886, min and max buffer occupancy 237 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7955.9, 25364.0, 134604.0. Sync error: 1845.1 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 18790; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8955, min and max buffer occupancy 236 and 266. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8016.2, 25711.0, 139392.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.6, 25707.0, 143479.0. Sync error: 1804.1 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 22548; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9698, min and max buffer occupancy 235 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8008.0, 25576.8, 152379.0. Sync error: 1590.3 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 26306; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9539, min and max buffer occupancy 236 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7959.2, 25588.5, 138091.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7970.9, 25376.1, 138451.0. Sync error: 1701.4 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 30064; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9526, min and max buffer occupancy 234 and 266. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7962.7, 25476.1, 150576.0. Sync error: 1604.3 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 33822; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9645, min and max buffer occupancy 236 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7963.1, 25673.6, 168165.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8011.2, 25738.8, 145943.0. Sync error: 1706.4 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 37580; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9868, min and max buffer occupancy 234 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7963.4, 25549.9, 144595.0. Sync error: 1713.7 (frames); net correction: 0.0 (ppm); corrections: 0.0 (ppm); total packets 41338; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 9623, min and max buffer occupancy 235 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8005.6, 25622.2, 150675.0. ....

[mikebrady]

That's very interesting, thanks. Going from a drift tolerance to 1,100 frames to 5,000 frames has resulted in Shairport Sync not doing any synchronisation at all, which is kinda good because it seems to mean a good drift tolerance is somewhere between the two figures. If you were interested, it would be worth dividing the interval using the method of bisections, so you should be able to arrive at a tolerance that gives you a synchronisation you can live with and doesn't cause over-compensation. A slop of 2,210 frames that I saw in the logs is 1/20 of a second, definitely audible!

[jordanade]

Thanks, I'm trying 2000 drift and it sounds much better without causing gaps. That might be the sweet spot. Can you explain the relationship between the drift setting and the sync error? Is drift the maximum allowed sync error before resynchronization occurs? But then what is resync_threshold (which is currently disabled) and how does it affect this process?

$ shairport-sync -a test -vvv Looking for the configuration file "/etc/shairport-sync.conf". Looking for configuration file at full path "/etc/shairport-sync.conf" Output device name is "hw:1,0". The processor is running little-endian. Version: "2.8.3.1-openssl-Avahi-ALSA-soxr-metadata" statistics_requester status is 1. daemon status is 0. rtsp listening port is 5000. udp base port is 6001. udp port range is 100. Shairport Sync player name is "test". Audio Output name is "(null)". on-start action is "(null)". on-stop action is "(null)". wait-cmd status is 0. mdns backend "(null)". userSuppliedLatency is 0. AirPlayLatency is -1. iTunesLatency is -1. forkedDaapdLatency is -1. stuffing option is "1". resync time is 0. allow a session to be interrupted: 0. busy timeout time is 120. drift tolerance is 2000 frames. password is "(null)". ignore_volume_control is 0. mono is 0. disable_synchronization is 0. audio backend desired buffer length is 11025. audio backend latency offset is 0. volume range in dB (zero means use the range specified by the mixer): 0. zeroconf regtype is "_raop._tcp". configuration file name "/etc/shairport-sync.conf" resolves to "/etc/shairport-sync.conf". metdata enabled is 0. metadata pipename is "(null)". metadata socket address is "(null)" port 0. metadata socket packet size is "500". get-coverart is 0. avahi: avahi_register. avahi: register_service. avahi: service '098F6BCD4621@test' group is not yet commited. avahi: request to add "_raop._tcp" service without metadata avahi: service '098F6BCD4621@test' group is registering. avahi: service '098F6BCD4621@test' successfully added. avahi: address advertised is: "fe80::c654:44ff:fe3a:e75". avahi: address advertised is: "10.0.0.2". New RTSP connection on port 5000 Client-Instance: C7728C810EF9622A. DACP-ID: C7728C810EF9622A. CSeq: 0. User-Agent: iTunes/7.6.2 (Windows; N;). Apple-Challenge: BkHbHsq6O3lrVFHzTTxWag==. Client-Instance: C7728C810EF9622A. DACP-ID: C7728C810EF9622A. CSeq: 1. User-Agent: iTunes/7.6.2 (Windows; N;). Content-Type: application/sdp. Content-Length: 570. Play connection from user agent "iTunes/7.6.2 (Windows; N;)". Client-Instance: C7728C810EF9622A. DACP-ID: C7728C810EF9622A. CSeq: 2. User-Agent: iTunes/7.6.2 (Windows; N;). Transport: RTP/AVP/UDP;unicast;interleaved=0-1;mode=record;control_port=58779;timing_port=32985. DACP-ID string seen: "C7728C810EF9622A". rtp_setup: cport=58779 tport=32985. Connection from IPv4: 10.0.0.20:60828 listening for audio, control and timing on ports 6001, 6002, 6003. Timing receiver -- Server RTP thread starting. Control receiver -- Server RTP thread starting. Audio receiver -- Server RTP thread starting. Timing sender thread starting. Client-Instance: C7728C810EF9622A. DACP-ID: C7728C810EF9622A. CSeq: 3. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. RTP-Info: seq=39936;rtptime=1249329781. Range: npt=0-. Flush requested up to 1249329780. It seems as if 0 is special. Client-Instance: C7728C810EF9622A. DACP-ID: C7728C810EF9622A. CSeq: 4. User-Agent: iTunes/7.6.2 (Windows; N;). Session: 1. Content-Type: text/parameters. Content-Length: 15. SET_PARAMETER Content-Type:"text/parameters". received parameters in SET_PARAMETER request. volume: -3.300000

syncing to seqno 39951. Using negotiated latency of 99225 frames. PCM handle name = 'hw:1,0' alsa device parameters: access type = RW_INTERLEAVED format = 'S16_LE' (Signed 16 bit Little Endian) subformat = 'STD' (Standard) number of channels = 2 number of significant bits = 16 rate = 44100 frames per second (precisely). precise (rational) rate = 44100.000 frames per second (i.e. 44100/1). period_time = 11609 us (>). period_size = 512 frames (precisely). buffer_time = 371519 us (>). buffer_size = 16384 frames (>). periods_per_buffer = 32 (precisely). Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7976.7, 21115.6, 142599.0. Sync error: -1315.0 (frames); net correction: 259.2 (ppm); corrections: 259.2 (ppm); total packets 3758; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 4342, min and max buffer occupancy 222 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7967.5, 20489.4, 155088.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8002.2, 18815.8, 141195.0. Sync error: -445.7 (frames); net correction: 455.1 (ppm); corrections: 455.1 (ppm); total packets 7516; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 6466, min and max buffer occupancy 226 and 262. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7973.3, 20785.8, 123697.0. Sync error: -250.6 (frames); net correction: 164.0 (ppm); corrections: 239.6 (ppm); total packets 11274; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7136, min and max buffer occupancy 226 and 261. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7999.6, 18701.8, 149311.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7971.7, 19440.1, 156153.0. Sync error: -204.2 (frames); net correction: 5.3 (ppm); corrections: 217.0 (ppm); total packets 15032; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8269, min and max buffer occupancy 227 and 263. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7998.5, 21915.1, 151745.0. Sync error: -248.9 (frames); net correction: -41.6 (ppm); corrections: 389.3 (ppm); total packets 18790; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7547, min and max buffer occupancy 227 and 266. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7962.6, 24817.2, 145791.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8067.4, 23717.1, 136036.0. Sync error: -220.1 (frames); net correction: 281.2 (ppm); corrections: 399.1 (ppm); total packets 22548; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 5559, min and max buffer occupancy 223 and 270. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7910.6, 21882.9, 136137.0. Sync error: 78.8 (frames); net correction: -69.5 (ppm); corrections: 600.2 (ppm); total packets 26306; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 5615, min and max buffer occupancy 231 and 269. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7991.2, 25312.5, 143832.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7976.3, 23300.3, 140029.0. Sync error: -16.5 (frames); net correction: 49.9 (ppm); corrections: 461.1 (ppm); total packets 30064; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7008, min and max buffer occupancy 228 and 267. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7959.8, 25234.0, 138867.0. Sync error: -88.4 (frames); net correction: 0.0 (ppm); corrections: 172.4 (ppm); total packets 33822; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8232, min and max buffer occupancy 236 and 263. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8011.8, 25480.2, 143269.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7964.3, 25436.5, 134208.0. Sync error: -34.6 (frames); net correction: -127.0 (ppm); corrections: 462.6 (ppm); total packets 37580; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7636, min and max buffer occupancy 236 and 265. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8017.2, 23364.4, 138630.0. Sync error: -61.4 (frames); net correction: 224.5 (ppm); corrections: 224.5 (ppm); total packets 41338; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 7522, min and max buffer occupancy 218 and 267. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7954.7, 18857.0, 127769.0. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 8003.7, 22097.5, 148308.0. Sync error: 275.4 (frames); net correction: -174.6 (ppm); corrections: 514.8 (ppm); total packets 45096; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 8225, min and max buffer occupancy 215 and 264. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7961.6, 21396.4, 130027.0. Sync error: -9.7 (frames); net correction: -129.3 (ppm); corrections: 306.2 (ppm); total packets 48854; missing packets 0; late packets 0; too late packets 0; resend requests 0; min DAC queue size 6548, min and max buffer occupancy 215 and 268. Packet reception interval stats: mean, standard deviation and max for the last 2,500 packets in microseconds: 7981.6, 19868.5, 139607.0.

[mikebrady]

That sounds good.

To explain the two settings, every time a new packet of 352 frames of audio is about to be sent to the DAC – approximately every 8 milliseconds – Shairport Sync calculates the latency error, that is, the gap between the time then and the time the next audio frame should be played.

If the latency error is less than plus or minus the drift (88 frames, 2 milliseconds by default) then Shairport Sync does nothing. If it's outside the drift amount, then Shairport Sync may add or remove a frame as appropriate.

If the latency error is outside the much greater resynchronization limits (2,200 frames, 50 milliseconds by default), then Shairport Sync "starts over" as it were – it tries to completely resynchronize.

The thing is, if the source is an iOS device or iTunes, the accuracy of the source timing seems to be much higher (more than 10 times higher) than timing coming from Android.

If you wanted to experiment a bit more, turn on resynchronisation with a threshold of, say, 10000.

[joerg-krause]

@mikebrady Many thanks for the explanation about the two setting! Do you like to add it to the README?

[mikebrady]

Thank Jörg-Krause. I'll put it on "The List" :)

[mikebrady]

Fixed, sort of.