Description: During Qobuz streaming via the upmpdcli-qobuz interface, random jumps to the next track.
More details: The jumps are apparently random, not easy to reproduce but not rare. In average, I observe one jump ever album, sometimes more. Typically, restarting replay from the track at which the jump has occurred does not yield another jump. The jumps are observed with different control points (Linn Kazoo iOS and Android, BubbleUPnP) and seem to affect also the Tidal interface. Some microRendu users have also experienced the same problem, see https://www.computeraudiophile.com/forums/topic/38113-help-trouble-shooting-skip-to-next-track-problem-in-my-streaming-setup/.
Important: Qobuz streaming to upmpdcli using the Qobuz interface of the BubbleUPnP control point (instead of upmpdcli-qobuz) works flawlessly on the same system. This strongly suggests that the jumps are caused by the upmpdcli-qobuz interface.
System: Linux rpi5 4.14.34-v7+ #1110 SMP Mon Apr 16 15:18:51 BST 2018 armv7l GNU/Linux
upmpdcli: Upmpdcli 1.2.16 libupnpp 0.16.1
Discussion
-
nbpf
2018-05-22Thanks! I have played a little bit around with curl options (no-keepalive, ignore-content-length) via .curlrc but I doubt that .curlrc is accounted for for when curl is called from within MPD. Given that it is very difficult to reproduce the same sequence of failures, I would normally think that these are network or Qobuz problems. The truth, however, is that the four albums that make a lot of troubles stream perfectly fine via the Qobuz app or even via the BubbleUPnP app when the selected renderer is the app's local renderer. It is only when the files are fetched by MPD (no matter whether upon requests from upmpdcli or from BubbleUPnP) that the failures occur. I think that the relevant code in MPD is in src/lib/curl/Request.cxx but I would have to invest some time to be able to do some meaningful hacking.
-
nbpf
2018-05-23Perhaps two more pieces of information: the failures occur no matter whether I stream mp3 files or flac files from the same albums. I have streamed the 4 Mahler's albums from Adam Fischer and the Düsseldorfer Symphoniker in a loop and what I can say at the end of the day is that MPD 0.20.19 has less failures than MPD 0.19.21. The two versions were running on different machines, though: a fitpc3 and a Raspberry Pi 3B+.
-
medoc
2018-05-25I have started some tests on the Mahler albums (using a non-mpd curl fetcher).
One thing I thought of which could explain the difference would be if the apps which never fail actually retry the transfer when it is interrupted. Given the buffer sizes, there are several seconds available for reconnecting and seeking to the point of failure, this should be quite feasible.
This should be visible in wireshark if it happens.
Last edit: medoc 2018-05-25
-
nbpf
2018-05-26Have you managed to reproduce some of the failures using curl but not MPD? I have very little understanding of communication protocols but what I can say from the tests that I have done so far is that curl failures in MPD seem to always happen on certain albums. For example, here is a MPD log of about 12 hours of streaming:
May 25 19:03 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47118439"
May 25 19:11 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47118440"
May 25 19:18 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47118441"
May 25 19:37 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47118442"
May 25 19:41 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47118443"
May 25 19:51 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47118444"
May 25 20:02 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396316"
May 25 20:07 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396318"
May 25 20:17 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396320"
May 25 20:35 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396322"
May 25 20:42 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396324"
May 25 21:00 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396326"
May 25 21:06 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396328"
May 25 21:08 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396330"
May 25 21:21 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396332"
May 25 21:36 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396334"
May 25 21:41 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396336"
May 25 21:43 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396338"
May 25 21:47 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396340"
May 25 21:50 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396342"
May 25 21:57 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396344"
May 25 21:59 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396346"
May 25 22:10 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396348"
May 25 22:18 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396350"
May 25 22:22 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396352"
May 25 22:25 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396354"
May 25 22:33 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396356"
May 25 22:42 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396358"
May 25 22:47 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396360"
May 25 22:58 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396362"
May 25 23:07 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396364"
May 25 23:10 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396366"
May 25 23:15 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396368"
May 25 23:23 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396370"
May 25 23:29 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396372"
May 25 23:58 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=40396374"
May 26 00:05 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933672"
May 26 00:14 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933673"
May 26 00:17 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933674"
May 26 00:22 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933675"
May 26 00:24 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933676"
May 26 00:27 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933677"
May 26 00:30 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933678"
May 26 00:34 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933679"
May 26 00:41 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933680"
May 26 00:46 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933681"
May 26 00:50 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933682"
May 26 00:52 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933683"
May 26 00:55 : exception: Failed to decode http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933685
May 26 00:55 : exception: nested: CURL failed: Empty reply from server
May 26 00:55 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933684"
May 26 00:55 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933685"
May 26 00:56 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933685"
May 26 00:58 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933686"
May 26 01:06 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933687"
May 26 01:07 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933688"
May 26 01:14 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933689"
May 26 01:16 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933690"
May 26 01:26 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933691"
May 26 01:28 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933692"
May 26 01:29 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933693"
May 26 01:31 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933694"
May 26 01:32 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933695"
May 26 01:37 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933696"
May 26 01:38 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933697"
May 26 01:40 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933698"
May 26 01:42 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933699"
May 26 01:46 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=41933700"
May 26 01:49 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533862"
May 26 01:54 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533863"
May 26 01:59 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533864"
May 26 02:07 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533865"
May 26 02:10 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533866"
May 26 02:14 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533867"
May 26 02:20 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533868"
May 26 02:23 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533869"
May 26 02:28 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533870"
May 26 02:39 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533871"
May 26 02:46 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=533872"
May 26 02:52 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542509"
May 26 02:58 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542510"
May 26 03:06 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542511"
May 26 03:12 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542512"
May 26 03:20 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542513"
May 26 03:26 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542514"
May 26 03:49 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=44542515"
May 26 03:55 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598522"
May 26 03:56 : exception: CURL failed: Recv failure: Connection reset by peer
May 26 03:56 : exception: Failed to decode http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598524
May 26 03:56 : exception: nested: CURL failed: Empty reply from server
May 26 03:56 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598523"
May 26 03:56 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598524"
May 26 04:06 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598524"
May 26 04:17 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598525"
May 26 04:29 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598526"
May 26 04:39 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598527"
May 26 04:53 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=46598528"
May 26 04:56 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445416"
May 26 04:58 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445417"
May 26 05:01 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445418"
May 26 05:04 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445419"
May 26 05:06 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445420"
May 26 05:09 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445421"
May 26 05:13 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445422"
May 26 05:16 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445423"
May 26 05:21 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445424"
May 26 05:25 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445425"
May 26 05:28 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445426"
May 26 05:31 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445427"
May 26 05:35 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445428"
May 26 05:39 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445429"
May 26 05:42 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445430"
May 26 05:45 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445431"
May 26 05:48 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445432"
May 26 05:51 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445433"
May 26 05:53 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445434"
May 26 05:56 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445435"
May 26 06:00 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445436"
May 26 06:04 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47445437"
May 26 06:20 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=48178645"
May 26 06:31 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=48178646"
May 26 06:42 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=48178647"
May 26 06:52 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=48178648"
May 26 07:04 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=48178649"It contains only 2 curl failures and only the first one (at May 26 00:55) is relevant: the second one is caused by the daily disconnect/reconnect of the DSL modem. By contrast, streaming the Mahler's albums yields more frequent failures and " transfer closed with ... bytes remaining to read" failures instead of "Empty reply from server" failures.
-
medoc
2018-05-26I had 1 failure in 4 hours yesterday while transferring the Mahler albums.
My feeling at this point is that the Qobuz servers do have some relatively rare transfer issues, and that the players which do not fail probably retry the transfers internally.
I am going to implement a retry in the test program to see how it goes.
-
nbpf
2018-05-26Great, thanks! Here is the result of adding a few Mahler's albums to the previous playlist:
May 26 07:37 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47572574"
May 26 07:51 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47572575"
May 26 08:08 : exception: CURL failed: transfer closed with 3861305 bytes remaining to read
May 26 08:08 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47572576"
May 26 08:19 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47572577"
May 26 08:31 : exception: CURL failed: transfer closed with 15262220 bytes remaining to read
May 26 08:31 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=47572578"
May 26 08:48 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=42623121"
May 26 08:57 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=42623122"
May 26 09:11 : exception: CURL failed: transfer closed with 29615632 bytes remaining to read
May 26 09:11 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=42623123"
May 26 09:20 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=42623124"
May 26 09:39 : exception: CURL failed: transfer closed with 10493632 bytes remaining to read
May 26 09:39 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=34297158"
May 26 09:55 : player: played "http://192.168.178.101:49149/qobuz/track?version=1&trackId=34297160"As you can see, we now have a very different failure pattern: almost one failure every second track! Assuming that the data sent by the Qobuz server are correct, the only obvious qualitative difference between these tracks and the previous ones seems to be their length.
The fact that most failures occur towards the end of the tracks (with not many bytes "remaining to read") suggests that the track length does in fact matter. Perhaps there is a computation done on the receiver side (buffer length, etc.) that becomes incorrect when the track length exceeds a certain threshold?
If you are able to fetch the tracks with curl outside MPD, perhaps it could also be worth playing around with the "--ignore-content-length" and "--no-keepalive" options. I would try that but I do not know which Qobuz server to curl.
Last edit: nbpf 2018-05-26
-
medoc
2018-05-26I never see such a failure rate. I also feel that there is something variable on the Qobuz side, maybe what cache server you are connected to (they most probably use a cdn).
It's very difficult to draw conclusions on a process with low occurrence and unknown random varying factors.
-
nbpf
2018-05-26I agree but while sometimes the Mahler's albums (I usually test them in the order 5th, 4th, 7th, 1st and then 5th again) go through with perhaps only three failures, I can clearly see failure patterns in my setup: I very rarely observe failures on the 7th and on the 1th. On the other hand, the 5th and the 4th almost always make troubles.
What is really strange is that the issue doe not seem to affect the Qobuz app. Also, notice that the BubbleUPnP control point streams perfectly fine all Mahler's albums through the local renderer.
But the same BubbleUPnP control point yields failures when the selected renderer is upmpdcli and hence MPD. This again supports your conjecture that the Qobuz app renderer and the BubbleUPnP renderer are using different fetching approaches than MPD.
Last edit: nbpf 2018-05-26
-
nbpf
2018-06-10It seems to be primarily a problem with long tracks: no way to stream the first track of Bruckner's 9th, no matter whether by Abbado or by Mazeel, from the beginning to the end with upmpdcli/MPD.