Snapcast: out-sync between clients of different devices

Created on 27 Nov 2017  路  9Comments  路  Source: badaix/snapcast

When I using the same type device as clients, I can feel that the clients work well in sync. However, if the clients run in different device, I can feel out-sync clearly. In my test, different device means ubuntu (may not the same version) in two different computers. Does it normal, or I have done something wrong?

Most helpful comment

I seem to have the same issue. Running snapserver in a Docker container on a home server, and multiple snapclients on Raspberry Pi 3s (a mix of direct 3.5mm and DAC outputs), one RPi 2 and a C.H.I.P.

The clients have varying amounts of latency, and eventually, they do sync up, only to de-sync again after a few minutes, and so on. I'd understand if the output-to-speaker latency were constant, but it's strange that the streams end up syncing occasionally, after several minutes of playing.

Is there anything I can do to debug this issue further? Any logs I could tail, on the server or client?

All 9 comments

Did you use a snapclient instance for EACH sound device? Don't access sound devices directly (e.g. ALSA, Pulseaudio, etc.)

Snapclient cannot automatically compensate for the latency between its output and your speakers, so if that latency is different on different machines (due to different software, hardware, or both) the clients will sound out of sync - but always by the same amount.

If that's your issue, I know the android client provides an interface for adjusting the latency for individual clients. I've had to do that before and just adjusted till it sounded right.

I seem to have the same issue. Running snapserver in a Docker container on a home server, and multiple snapclients on Raspberry Pi 3s (a mix of direct 3.5mm and DAC outputs), one RPi 2 and a C.H.I.P.

The clients have varying amounts of latency, and eventually, they do sync up, only to de-sync again after a few minutes, and so on. I'd understand if the output-to-speaker latency were constant, but it's strange that the streams end up syncing occasionally, after several minutes of playing.

Is there anything I can do to debug this issue further? Any logs I could tail, on the server or client?

I usually have a similar problem that clients fall out of sync after a few minutes of playing. I feed the snapserver with a pipe from librespot. Changing the song manually will sync the playback of the devices again. 馃

@Gronis, did you try the librespot included with snapserver as well? Did you notice any syncing differences between the two?

I'm using the included version, but was considering moving to a pipe so I can control the librespot (or spotifyd/raspotify) daemon separately. It would be nice to hear from someone who tried it, whether it helps the de-sync issues or not.

I didn't know that snapserver came with a version of librespot. I have only used the pipe version. In my setup, I run snapserver and librepot in two separate docker containers, with snapclient installed on raspberry pi's. I don't think librespot has anything to do with the de-sync issues.

I've just realised why it gets out of sync. When I start snap client it can be offset +/- 100ms, and it syncs over time (1ms each 1s). So after 100-20 seconds, all clients are in sync (out of sync for me since I didn't realised they were out of sync from the start) This is a client log from my setup:

volumio@living-room:~$ sudo /usr/bin/snapclient --user snapclient:audio -h 192.168.1.102 -s equal --hostID living-room --latency 80
2018-10-03 20-19-17 [Info] Latency: 80
2018-10-03 20-19-17 [Notice] Connected to 192.168.1.102
2018-10-03 20-19-17 [Info] My MAC: "b8:27:eb:f5:9a:e6", socket: 6
2018-10-03 20-19-17 [Info] ServerSettings - buffer: 400, latency: 0, volume: 100, muted: 0
metadata:{"STREAM":"Spotify"}
2018-10-03 20-19-17 [Info] Codec: flac
2018-10-03 20-19-17 [Notice] sampleformat: 44100:16:2
2018-10-03 20-19-17 [Info] frames: 5513
2018-10-03 20-19-17 [Info] Failed to get chunk
2018-10-03 20-19-17 [Info] age > 200: -296
2018-10-03 20-19-17 [Info] sleep < -bufferDuration/2: -296 < -62, sleep: -301
2018-10-03 20-19-17 [Info] sleep < -bufferDuration/2: -301 < -62, sleep: -162
2018-10-03 20-19-17 [Info] sleep < -bufferDuration/2: -162 < -62, sleep: -37
2018-10-03 20-19-17 [Info] diff to server [ms]: 0.896
2018-10-03 20-19-17 [Info] Sleep -37, age: -37, bufferDuration: 125
2018-10-03 20-19-17 [Info] Chunk: -376  -376    -376    -376    1   241
2018-10-03 20-19-18 [Info] Chunk: -375  -375    -375    -375    1   139
2018-10-03 20-19-18 [Info] Sleep -36, age: -36, bufferDuration: 125
2018-10-03 20-19-19 [Info] Chunk: -368  -368    -368    -368    1   139
2018-10-03 20-19-20 [Info] Chunk: -361  -361    -361    -361    1   139
2018-10-03 20-19-20 [Info] Sleep -35, age: -35, bufferDuration: 125
2018-10-03 20-19-21 [Info] Chunk: -354  -354    -354    -354    1   139
2018-10-03 20-19-21 [Info] Sleep -34, age: -34, bufferDuration: 125
2018-10-03 20-19-22 [Info] Chunk: -346  -346    -346    -346    1   139
2018-10-03 20-19-22 [Info] Sleep -34, age: -33, bufferDuration: 125
2018-10-03 20-19-22 [Info] Sleep -33, age: -35, bufferDuration: 125
2018-10-03 20-19-22 [Info] Sleep -33, age: -33, bufferDuration: 125
2018-10-03 20-19-23 [Info] Chunk: -330  -330    -330    -330    1   140
2018-10-03 20-19-24 [Info] Chunk: -330  -330    -330    -330    1   139
2018-10-03 20-19-24 [Info] Sleep -32, age: -32, bufferDuration: 125
2018-10-03 20-19-25 [Info] Chunk: -322  -322    -322    -322    1   139
2018-10-03 20-19-25 [Info] Sleep -31, age: -33, bufferDuration: 125
2018-10-03 20-19-25 [Info] Sleep -31, age: -31, bufferDuration: 125
2018-10-03 20-19-25 [Info] Sleep -31, age: -32, bufferDuration: 125
2018-10-03 20-19-25 [Info] Sleep -31, age: -31, bufferDuration: 125
2018-10-03 20-19-26 [Info] Chunk: -315  -315    -315    -315    1   139
2018-10-03 20-19-26 [Info] Sleep -30, age: -30, bufferDuration: 125
2018-10-03 20-19-27 [Info] Chunk: -308  -308    -308    -308    1   139
2018-10-03 20-19-28 [Info] Chunk: -301  -301    -301    -301    1   139
2018-10-03 20-19-28 [Info] Sleep -29, age: -29, bufferDuration: 125
2018-10-03 20-19-28 [Info] Sleep -28, age: -30, bufferDuration: 125
2018-10-03 20-19-28 [Info] Sleep -28, age: -29, bufferDuration: 125
2018-10-03 20-19-29 [Info] Chunk: -292  -292    -292    -292    1   139
2018-10-03 20-19-29 [Info] Sleep -28, age: -28, bufferDuration: 125
2018-10-03 20-19-30 [Info] Chunk: -285  -285    -285    -285    1   139
2018-10-03 20-19-30 [Info] Sleep -27, age: -29, bufferDuration: 125
2018-10-03 20-19-30 [Info] Sleep -27, age: -28, bufferDuration: 125
2018-10-03 20-19-30 [Info] Sleep -27, age: -27, bufferDuration: 125
2018-10-03 20-19-31 [Info] Chunk: -279  -279    -279    -279    1   139
2018-10-03 20-19-31 [Info] Sleep -26, age: -28, bufferDuration: 125
2018-10-03 20-19-31 [Info] Sleep -26, age: -27, bufferDuration: 125
2018-10-03 20-19-32 [Info] Chunk: -271  -271    -271    -271    1   139
2018-10-03 20-19-32 [Info] Sleep -26, age: -26, bufferDuration: 125
2018-10-03 20-19-32 [Info] Sleep -25, age: -27, bufferDuration: 125
2018-10-03 20-19-32 [Info] Sleep -25, age: -26, bufferDuration: 125
2018-10-03 20-19-33 [Info] Chunk: -263  -263    -263    -263    1   139
2018-10-03 20-19-33 [Info] Sleep -25, age: -25, bufferDuration: 125
2018-10-03 20-19-33 [Info] Sleep -24, age: -26, bufferDuration: 125
2018-10-03 20-19-34 [Info] Sleep -24, age: -25, bufferDuration: 125
2018-10-03 20-19-34 [Info] Chunk: -254  -254    -254    -254    1   139
2018-10-03 20-19-34 [Info] Sleep -24, age: -24, bufferDuration: 125
2018-10-03 20-19-35 [Info] Chunk: -247  -247    -247    -247    1   139
2018-10-03 20-19-36 [Info] Chunk: -241  -241    -241    -241    1   139
2018-10-03 20-19-36 [Info] Sleep -22, age: -23, bufferDuration: 125
2018-10-03 20-19-37 [Info] Chunk: -233  -233    -233    -233    1   139
2018-10-03 20-19-37 [Info] Sleep -21, age: -22, bufferDuration: 125
2018-10-03 20-19-38 [Info] Chunk: -224  -224    -224    -224    1   139
2018-10-03 20-19-38 [Info] Sleep -20, age: -21, bufferDuration: 125
2018-10-03 20-19-39 [Info] Chunk: -216  -216    -216    -216    1   139
2018-10-03 20-19-40 [Info] Sleep -19, age: -20, bufferDuration: 125
2018-10-03 20-19-40 [Info] Chunk: -204  -204    -204    -204    1   139
2018-10-03 20-19-40 [Info] Sleep -19, age: -21, bufferDuration: 125
2018-10-03 20-19-40 [Info] Sleep -19, age: -20, bufferDuration: 125
2018-10-03 20-19-41 [Info] Chunk: -209  -209    -209    -209    1   137
2018-10-03 20-19-41 [Info] Sleep -19, age: -19, bufferDuration: 125
2018-10-03 20-19-41 [Info] Sleep -18, age: -20, bufferDuration: 125
2018-10-03 20-19-41 [Info] Sleep -18, age: -19, bufferDuration: 125
2018-10-03 20-19-42 [Info] Chunk: -194  -194    -194    -194    1   138
2018-10-03 20-19-42 [Info] Sleep -17, age: -18, bufferDuration: 125
2018-10-03 20-19-42 [Info] Sleep -17, age: -19, bufferDuration: 125
2018-10-03 20-19-42 [Info] Sleep -17, age: -18, bufferDuration: 125
2018-10-03 20-19-43 [Info] Sleep -17, age: -19, bufferDuration: 125
2018-10-03 20-19-43 [Info] Chunk: -196  -196    -196    -196    1   137
2018-10-03 20-19-43 [Info] Sleep -17, age: -18, bufferDuration: 125
2018-10-03 20-19-44 [Info] Chunk: -185  -185    -185    -185    1   138
2018-10-03 20-19-44 [Info] Sleep -16, age: -17, bufferDuration: 125
2018-10-03 20-19-44 [Info] Sleep -16, age: -18, bufferDuration: 125
2018-10-03 20-19-44 [Info] Sleep -16, age: -17, bufferDuration: 125
2018-10-03 20-19-44 [Info] Sleep -16, age: -16, bufferDuration: 125
2018-10-03 20-19-44 [Info] Sleep -16, age: -17, bufferDuration: 125
2018-10-03 20-19-45 [Info] Chunk: -174  -174    -174    -174    1   138
2018-10-03 20-19-45 [Info] Sleep -15, age: -16, bufferDuration: 125
2018-10-03 20-19-45 [Info] Sleep -15, age: -17, bufferDuration: 125
2018-10-03 20-19-45 [Info] Sleep -15, age: -16, bufferDuration: 125
2018-10-03 20-19-46 [Info] Chunk: -166  -166    -166    -166    1   139
2018-10-03 20-19-46 [Info] Sleep -14, age: -15, bufferDuration: 125
2018-10-03 20-19-47 [Info] Chunk: -158  -158    -158    -158    1   139
2018-10-03 20-19-47 [Info] Sleep -13, age: -16, bufferDuration: 125
2018-10-03 20-19-48 [Info] Sleep -13, age: -15, bufferDuration: 125
2018-10-03 20-19-48 [Info] Chunk: -151  -151    -151    -151    1   139
2018-10-03 20-19-48 [Info] Sleep -13, age: -14, bufferDuration: 125
2018-10-03 20-19-49 [Info] Sleep -12, age: -15, bufferDuration: 125
2018-10-03 20-19-49 [Info] Chunk: -151  -151    -151    -151    1   139
2018-10-03 20-19-49 [Info] Sleep -12, age: -14, bufferDuration: 125
2018-10-03 20-19-49 [Info] Sleep -12, age: -13, bufferDuration: 125
2018-10-03 20-19-50 [Info] Chunk: -136  -136    -136    -136    1   139
2018-10-03 20-19-50 [Info] Sleep -11, age: -12, bufferDuration: 125
2018-10-03 20-19-50 [Info] Sleep -11, age: -13, bufferDuration: 125
2018-10-03 20-19-50 [Info] Sleep -11, age: -12, bufferDuration: 125
2018-10-03 20-19-51 [Info] Chunk: -126  -126    -126    -126    1   139
2018-10-03 20-19-51 [Info] Sleep -10, age: -13, bufferDuration: 125
2018-10-03 20-19-51 [Info] Sleep -10, age: -11, bufferDuration: 125
2018-10-03 20-19-52 [Info] Chunk: -114  -114    -114    -114    1   140
2018-10-03 20-19-52 [Info] Sleep -10, age: -12, bufferDuration: 125
2018-10-03 20-19-52 [Info] Sleep -10, age: -11, bufferDuration: 125
2018-10-03 20-19-52 [Info] Sleep -9, age: -10, bufferDuration: 125
2018-10-03 20-19-52 [Info] Sleep -9, age: -11, bufferDuration: 125
2018-10-03 20-19-53 [Info] Sleep -9, age: -10, bufferDuration: 125
2018-10-03 20-19-53 [Info] Chunk: -109  -109    -109    -109    1   138
2018-10-03 20-19-53 [Info] Sleep -9, age: -11, bufferDuration: 125
2018-10-03 20-19-53 [Info] Sleep -9, age: -10, bufferDuration: 125
2018-10-03 20-19-54 [Info] Sleep -8, age: -11, bufferDuration: 125
2018-10-03 20-19-54 [Info] Chunk: -114  -114    -114    -114    1   137
2018-10-03 20-19-54 [Info] Sleep -8, age: -9, bufferDuration: 125
2018-10-03 20-19-54 [Info] Sleep -8, age: -10, bufferDuration: 125
2018-10-03 20-19-54 [Info] Sleep -8, age: -9, bufferDuration: 125
2018-10-03 20-19-54 [Info] Sleep -8, age: -10, bufferDuration: 125
2018-10-03 20-19-54 [Info] Sleep -8, age: -9, bufferDuration: 125
2018-10-03 20-19-55 [Info] Chunk: -95   -95 -95 -95 1   138
2018-10-03 20-19-55 [Info] Sleep -7, age: -10, bufferDuration: 125
2018-10-03 20-19-55 [Info] Sleep -7, age: -8, bufferDuration: 125
2018-10-03 20-19-55 [Info] Sleep -7, age: -9, bufferDuration: 125
2018-10-03 20-19-56 [Info] Sleep -7, age: -8, bufferDuration: 125
2018-10-03 20-19-56 [Info] Chunk: -84   -84 -84 -84 1   139
2018-10-03 20-19-56 [Info] Sleep -6, age: -9, bufferDuration: 125
2018-10-03 20-19-56 [Info] Sleep -6, age: -8, bufferDuration: 125
2018-10-03 20-19-57 [Info] Sleep -6, age: -7, bufferDuration: 125
2018-10-03 20-19-57 [Info] Chunk: -79   -79 -79 -79 1   138
2018-10-03 20-19-57 [Info] Sleep -6, age: -8, bufferDuration: 125
2018-10-03 20-19-57 [Info] Sleep -5, age: -7, bufferDuration: 125
2018-10-03 20-19-57 [Info] Sleep -5, age: -8, bufferDuration: 125
2018-10-03 20-19-58 [Info] Sleep -5, age: -7, bufferDuration: 125
2018-10-03 20-19-58 [Info] Chunk: -76   -76 -76 -76 1   138
2018-10-03 20-19-58 [Info] Sleep -5, age: -6, bufferDuration: 125
2018-10-03 20-19-58 [Info] Sleep -5, age: -7, bufferDuration: 125
2018-10-03 20-19-59 [Info] Sleep -4, age: -6, bufferDuration: 125
2018-10-03 20-19-59 [Info] Chunk: -68   -68 -68 -68 1   138
2018-10-03 20-19-59 [Info] Sleep -4, age: -7, bufferDuration: 125
2018-10-03 20-19-59 [Info] Sleep -4, age: -6, bufferDuration: 125
2018-10-03 20-19-59 [Info] Sleep -4, age: -5, bufferDuration: 125
2018-10-03 20-19-59 [Info] Sleep -4, age: -6, bufferDuration: 125
2018-10-03 20-19-59 [Info] Sleep -4, age: -5, bufferDuration: 125
2018-10-03 20-20-00 [Info] Chunk: -58   -58 -58 -58 1   138
2018-10-03 20-20-00 [Info] Sleep -3, age: -6, bufferDuration: 125
2018-10-03 20-20-00 [Info] Sleep -3, age: -5, bufferDuration: 125
2018-10-03 20-20-00 [Info] Sleep -3, age: -6, bufferDuration: 125
2018-10-03 20-20-00 [Info] Sleep -3, age: -5, bufferDuration: 125
2018-10-03 20-20-00 [Info] Sleep -3, age: -4, bufferDuration: 125
2018-10-03 20-20-01 [Info] Sleep -3, age: -5, bufferDuration: 125
2018-10-03 20-20-01 [Info] Chunk: -51   -51 -51 -51 1   139
2018-10-03 20-20-01 [Info] Sleep -3, age: -4, bufferDuration: 125
2018-10-03 20-20-01 [Info] Sleep -2, age: -5, bufferDuration: 125
2018-10-03 20-20-01 [Info] Sleep -2, age: -4, bufferDuration: 125
2018-10-03 20-20-01 [Info] Sleep -2, age: -5, bufferDuration: 125
2018-10-03 20-20-01 [Info] Sleep -2, age: -4, bufferDuration: 125
2018-10-03 20-20-02 [Info] Chunk: -42   -42 -42 -42 1   139
2018-10-03 20-20-02 [Info] Sleep -2, age: -3, bufferDuration: 125
2018-10-03 20-20-02 [Info] Sleep -2, age: -4, bufferDuration: 125
2018-10-03 20-20-02 [Info] Sleep -2, age: -3, bufferDuration: 125
2018-10-03 20-20-02 [Info] Sleep -1, age: -4, bufferDuration: 125
2018-10-03 20-20-03 [Info] Sleep -1, age: -3, bufferDuration: 125
2018-10-03 20-20-03 [Info] Chunk: -32   -32 -32 -32 1   140
2018-10-03 20-20-03 [Info] Sleep -1, age: -2, bufferDuration: 125
2018-10-03 20-20-03 [Info] Sleep 0, age: -3, bufferDuration: 125
2018-10-03 20-20-03 [Info] Sleep 0, age: -2, bufferDuration: 125
2018-10-03 20-20-04 [Info] Sleep 0, age: -3, bufferDuration: 125
2018-10-03 20-20-04 [Info] Chunk: -32   -32 -32 -32 1   139
2018-10-03 20-20-04 [Info] Sleep 0, age: -2, bufferDuration: 125
2018-10-03 20-20-04 [Info] Sleep 0, age: -1, bufferDuration: 125
2018-10-03 20-20-05 [Info] Sleep 0
2018-10-03 20-20-05 [Info] Chunk: -16   -16 -16 -16 1   140
2018-10-03 20-20-06 [Info] Chunk: -17   -17 -17 -17 9   140
2018-10-03 20-20-07 [Info] Chunk: -16   -17 -17 -17 17  140
2018-10-03 20-20-08 [Info] Chunk: -27   -17 -17 -17 25  139
2018-10-03 20-20-09 [Info] Chunk: -20   -17 -17 -17 33  139
2018-10-03 20-20-10 [Info] Chunk: -15   -16 -17 -17 41  140
2018-10-03 20-20-11 [Info] Chunk: -15   -16 -17 -17 49  140

Is there a way to sync "faster" in the beginning (skip rather than slowly converge to sync)?

Also, I get this log on the same client when it goes out of sync with the other clients. When the "sleep" command has climbed back to 0, it is still out of sync. The only way to got it synced again is to restart snapclient.

2018-10-03 20-46-30 [Info] Chunk: -862  -869    -873    -7  500 139
2018-10-03 20-46-31 [Info] Chunk: -868  -868    -872    -7  500 139
2018-10-03 20-46-32 [Info] Chunk: -859  -865    -871    -8  500 139
2018-10-03 20-46-33 [Info] Chunk: -858  -865    -870    -8  500 139
2018-10-03 20-46-34 [Info] Chunk: -856  -859    -868    -856    500 139
2018-10-03 20-46-34 [Info] pBuffer->full() && (abs(median_) > 1): -85655
2018-10-03 20-46-34 [Info] Sleep -85, age: -86, bufferDuration: 125
2018-10-03 20-46-34 [Info] sleep < -bufferDuration/2: -85 < -62, sleep: -85
2018-10-03 20-46-34 [Info] sleep < -bufferDuration/2: -85 < -62, sleep: 39
2018-10-03 20-46-34 [Info] Sleep 39, age: 39, bufferDuration: 125
2018-10-03 20-46-34 [Info] Sleep 39, age: 38, bufferDuration: 125
2018-10-03 20-46-35 [Info] Chunk: 388   388 388 388 1   139
2018-10-03 20-46-35 [Info] Sleep 38, age: 37, bufferDuration: 125
2018-10-03 20-46-35 [Info] Sleep 38, age: 38, bufferDuration: 125
2018-10-03 20-46-36 [Info] Chunk: 382   382 382 382 1   139

please try the current master, which has much better synchronization

Was this page helpful?
0 / 5 - 0 ratings