A Roon remote stopped playing a song and seemed stuck. Pressing the pause and play button did not result in the song continuing. Only by skipping to the next song in the queue did the music continue playing. Odd behavior but I considered it a momentary network glitch with Qobuz’s platform.
After a while, I noticed that a Grafana chart I used to track Qobuz download speeds stopped showing data points:
At the timestamp when the chart stopped showing data, this was in the Roon Server logs:
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 rid:1 request ended – first block: 0 blocks read: 0 download speed: -256kbps response time: 153ms
To find how often the “-256kbps download speed” entry appears in the log files I executed the following commands from the Mac OS terminal:
find ~/Library -type d -maxdepth 1 \( -iname 'roon*' -o -iname 'raat*' \) -print0 | \
xargs -0 -I{} find {} -maxdepth 1 -type d -name 'Logs' -print0 | \
xargs -0 -I{} grep -r -- '-256kbps' {} | \
awk -F':' '{print $2":"$3":"$4"\t"$9}' | \
sort
Which produced:
03/14 18:37:39 Debug -256kbps response time
03/14 18:37:40 Debug -256kbps response time
03/14 18:37:40 Debug -256kbps response time
03/14 22:49:03 Debug -256kbps response time
03/15 01:17:47 Debug -256kbps response time
03/15 22:43:48 Debug -256kbps response time
03/15 22:43:50 Debug -256kbps response time
03/16 17:56:25 Debug -256kbps response time
03/16 20:41:06 Debug -256kbps response time
03/16 20:41:11 Debug -256kbps response time
03/17 01:05:38 Debug -256kbps response time
-----8<—snip—8<—snip—8<—snip—8<----
Roon Server continued to request the same audio file:
03/17 36,937 times
Here’s the relevant log entries that show what’s happening. The pattern of creating new requests repeats thousands of times without pause. Note the references to cache item “qo/531A4FB7”.
03/17 01:06:27 Info: FTMSI-B new FileCache qo/531A4FB7
/Users/me/Library/RoonServer/Cache/smc.db/bfc/237.cache
https://streaming-qobuz-std.akamaized.net/file
03/17 01:06:27 Debug: FTMSI-B Cache open file qo/531A4FB7 domain: zoneplayer:16 ordinal:137
03/17 01:06:27 Debug: FTMSI-B qo/531A4FB7 download status: DownloadNotStarted accessTimeout:False openFiles:1 prev:no
03/17 01:06:27 Trace: FTMSI-B 7 FileCache qo/531A4FB7 dwStatus:DownloadNotStarted files:1 accessTimeOut:False priorities: (‘zoneplayer:16’:137) → bw limit:0kbps
03/17 01:06:27 Debug: [easyhttp] [8698] GET to https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&intent=stream&request_sig=d3d28b2325fb1762b73df36eeaeeef63&request_ts=1773727586&track_id=342289703 returned after
338 ms, status code: 200, request body size: 0 B
03/17 01:06:27 Info: [iMac] [zoneplayer] Queueing: https://streaming-qobuz-std.akamaized.net/file
03/17 01:06:27 Info: FTMSI-B 7 FileCache qo/531A4FB7 dwStatus:DownloadNotStarted files:1 accessTimeOut:False priorities: (‘zoneplayer:16’:137) → bw limit:51200kbps
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 created new req 1 for block 0 p 4294967295; active requests 1
03/17 01:06:27 Debug: [easyhttp] [8702] GET to https://streaming-qobuz-std.akamaized.net/file?uid=3089804&eid=342289702&fmt=7&profile=raw&app_id=188245549&cid=2202808&etsp=1773731187&hmac=oq4BiRTBSx4zTCnP27xnUd-pqMg returned a
fter 153 ms, status code: 200, request body size: 0 B
03/17 01:06:27 Debug: FTMSI-B got length for qo/531A4FB7; 57.4 MBytes
03/17 01:06:27 Debug: FTMSI-B qo/531A4FB7 download status: FileLengthRetrieved accessTimeout:False openFiles:1 prev:(DownloadNotStarted,False,1)
03/17 01:06:27 Debug: FTMSI-B-OE set min bandwidth for qo/531A4FB7 to 3064 kbps
03/17 01:06:27 Info: FTMSI-B-OE qo/531A4FB7 rid:1 response took 153ms
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 rid:1 request ended – first block: 0 blocks read: 0 download speed: -256kbps response time: 153ms
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 rid:1 request ended – first block: 0 blocks read: 0 download speed: -256kbps response time: 153ms
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 interrupted req 1; missing block 0
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 created new req 2 for block 0 p 0; active requests 1
03/17 01:06:27 Debug: [easyhttp] [8703] GET to https://streaming-qobuz-std.akamaized.net/file?uid=3089804&eid=342289702&fmt=7&profile=raw&app_id=188245549&cid=2202808&etsp=1773731187&hmac=oq4BiRTBSx4zTCnP27xnUd-pqMg returned a
fter 116 ms, status code: 200, request body size: 0 B
03/17 01:06:27 Debug: FTMSI-B got length for qo/531A4FB7; 57.4 MBytes
03/17 01:06:27 Debug: FTMSI-B-OE set min bandwidth for qo/531A4FB7 to 3064 kbps
03/17 01:06:27 Info: FTMSI-B-OE qo/531A4FB7 rid:2 response took 116ms
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 rid:2 request ended – first block: 0 blocks read: 0 download speed: -256kbps response time: 116ms
03/17 01:06:27 Debug: FTMSI-B-OE qo/531A4FB7 interrupted req 2; missing block 0
My temporary workaround is to check end point devices that look like they’re playing music (although no music is heard) and stopping them. If that doesn’t work, restart the Roon Appliance.