RPi Playback Issues with Volume Leveling

[Neil_Small]

Yes. the playback zone is a Pi with USB out to the DAC.
Volume Leveling is enabled

[nathan2 (Nathan S)]

Just to confirm, you’re experiencing a skipping issue when playing, correct?

What sources have you experienced skipping with (Qobuz, Tidal, local music)?
What are the makes and models of your networking gear?
Have you tried playing music from System Output with DSP turned off?

[Neil_Small]

I only tested with Qobuz, and I only had one problem, with the album “Wish You Were Here”, which was pointed out to me by Ryan Herrera last evening.

My router is a NetGear AC1750. I can give you more details on the router if you want. Roon Bridge on the Pi 4B is running wirelessly, using 5GHz.

I can’t use system output; I use Roon Bridge with a Pi 4B. Sorry, but I don’t have time to drag the laptop running Core over and configure System Output.

I have not turned DSP off. I have no more errors.

As far as I’m concerned, there is no issue. It’s only happened once, testing with Ryan last night. Music has been playing error free all day today. Sorry I can’t be more help, but my time is limited today.

[noris]

Hi @Neil_Small,

Thank you for letting us know that information. If this issue occurs again, please note the exact local time + date of the occurrence. I would also give System Output a try to see if it displays the same behavior. Thanks!

[Neil_Small]

Apologies I couldn’t be more help, but with people visiting…

It did skip last night, after a full day of listening. The next song started, and then skipped to the following song. After that, it as fine and no more “skipping”. Again, this was with Qobuz, via Bridge (wifeless, 5GHz) to an iFi iDAC2.

Hopefully you’ve got an idea what’s causing this so you can isolate it and solve it. Thanks for such a terrific product. I’m tempted to buy two Lifetime Subscriptions, just in case…

[noris]

Hi @Neil_Small,

Thank you for the additional data point. If this happens again can you note the exact local time + date in your country of the occurrence? I would also be interested to know is “System Output” displays the same issue (as per my last message). If you can provide both pieces of info this would be a valuable data point, thanks!

[mike (Mike Fass)]

Hey @Neil_Small

We just released Build 505 with some changes that we think will help here. Can you give it a shot and let us know how it goes?

Thanks!

More details are here:

Roon 1.7 (Build 505) Is Live!

Hi all, Thanks everyone for all the kind words and great feedback about Roon 1.7! The last 5 days have been the busiest ever on the Community Site, and we’ve been tracking a few issues that we wanted to try and address before the holiday here in the States. We know that some of you have been having problems streaming Qobuz and TIDAL reliably since Roon 1.7 launched. While we have been unable to reliably reproduce this problem in-house, we undertook a thorough investigation, audited the code i…

[Neil_Small]

Mike,

I believe I found the error in the log files. Would you like me to send them to you?

Here’s where I received the error “Roon lost control of the audio device”, and it skipped from “Welcome to the Machine” to “Have a Cigar”:

11/22 20:09:52 Trace: [Living Room Pi] [Enhanced, 16/44 QOBUZ FLAC => 32/44] [100% buf] [PLAYING @ 7:09/7:31] Welcome to the Machine - Pink Floyd
11/22 20:09:55 Trace: [Caitlin's Room] [HighQuality, 24/44 QOBUZ FLAC => 16/44] [47% buf] [PLAYING @ 3:23/3:32] From the Dining Table - Harry Styles
11/22 20:09:55 Info: [stats] 6774mb Virtual, 1201mb Physical, 481mb Managed, 2454 Handles, 135 Threads
11/22 20:09:57 Trace: [rnet/RnetJsonClient] no data received for >10000ms. Killing connection.
11/22 20:09:57 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] lost client connection. Retrying
11/22 20:09:57 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] connecting (attempt 1)
11/22 20:09:57 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] connected
11/22 20:09:57 Trace: [rnet/RnetJsonClient] SENT {"request":"enumerate_devices","subscription_id":"0"}
11/22 20:09:57 Trace: [Living Room Pi] [Enhanced, 16/44 QOBUZ FLAC => 32/44] [100% buf] [PLAYING @ 7:14/7:31] Welcome to the Machine - Pink Floyd
11/22 20:09:58 Trace: [prebuffer] short read: 0 / 8820 fill=439157
11/22 20:09:59 Trace: [library] endmutation in 38ms
11/22 20:09:59 Warn: [Living Room Pi] [zoneplayer/raat] long rtt sync iFi (by AMR) HD USB Audio: realtime=1530947449129 rtt=88000us offset=-132567550us delta=60612us drift=54978us in 547.018s (100.506ppm, 361.823ms/hr)
11/22 20:10:00 Trace: [Living Room Pi] [zoneplayer/raat] sync iFi (by AMR) HD USB Audio: realtime=1532666059037 rtt=1000us offset=-132628940us delta=-61390us drift=-6411us in 548.885s (-11.681ppm, -42.050ms/hr)
11/22 20:10:01 Trace: [Caitlin's Room] [HighQuality, 24/44 QOBUZ FLAC => 16/44] [47% buf] [PLAYING @ 3:29/3:32] From the Dining Table - Harry Styles
11/22 20:10:02 Trace: [client/sonos] av_status
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos] state from device: PLAYING
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos]  zoneplayer state: Playing
11/22 20:10:02 Trace: [client/sonos] av_status
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos] state from device: STOPPED
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos]  zoneplayer state: Playing
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos] device stopped or paused by user, ending stream
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos] State transition Playing => Disconnected
11/22 20:10:02 Trace: [endpoint/sonos/uuid:RINCON_B8E937E665BC01400] check zone coordinator, device coordinator: RINCON_B8E937E665BC01400, roon coordinator: RINCON_B8E937E665BC01400
11/22 20:10:02 Trace: [client/sonos] timers stopped
11/22 20:10:02 Debug: [smc] [zoneplayer:4] Created domain
11/22 20:10:02 Debug: [smc] [zoneplayer:4] Removing ordinal 3
11/22 20:10:02 Debug: [smc] [zoneplayer:4] Destroyed domain
11/22 20:10:02 Warn: Track Stopped Due to LostEndpoint
11/22 20:10:02 Debug: [easyhttp] POST to https://www.qobuz.com/api.json/0.2/track/reportStreamingEnd?
11/22 20:10:02 Info: [Caitlin's Room] [zoneplayer] BufferingTrack == NextTrack during ClearQueuedMedia, setting _stop_on_next_track_transition
11/22 20:10:02 Info: [zone Caitlin's Room] OnPlayFeedback StoppedLostEndpoint
11/22 20:10:02 Info: [library] recorded play for profile bead7847-e39d-49bd-ad2e-2a2800abe97c: mediaid=202:0:40681602 metadataid= contentid=202:0:40681602 libraryid= isfromswim=False
11/22 20:10:02 Trace: [zone Caitlin's Room] Suspend
11/22 20:10:02 Info: [zone Caitlin's Room] OnPlayFeedback Stopped
11/22 20:10:02 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos] endstream, zp state: Disconnected
11/22 20:10:02 Trace: [Caitlin's Room] [zoneplayer/sonos] endstream, zp state: Disconnected
11/22 20:10:02 Trace: [Caitlin's Room] [HighQuality, 24/44 QOBUZ FLAC => 16/44] [47% buf] [PAUSED @ 3:30/3:32] From the Dining Table - Harry Styles
11/22 20:10:02 Info: Alert: Transport: playback_error_endpoint_lost
11/22 20:10:02 Info: Alert: Transport: playback_error_endpoint_lost
11/22 20:10:02 Trace: [Living Room Pi] [Enhanced, 16/44 QOBUZ FLAC => 32/44] [69% buf] [PLAYING @ 7:20/7:31] Welcome to the Machine - Pink Floyd
11/22 20:10:02 Trace: [library] endmutation in 119ms
11/22 20:10:02 Debug: [easyhttp] POST to https://www.qobuz.com/api.json/0.2/track/reportStreamingEnd? returned after 614 ms, status code: 200
11/22 20:10:07 Trace: [rnet/RnetJsonClient] no data received for >10000ms. Killing connection.
11/22 20:10:07 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] lost client connection. Retrying
11/22 20:10:07 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] connecting (attempt 1)
11/22 20:10:07 Trace: [Living Room Pi] [Enhanced, 16/44 QOBUZ FLAC => 32/44] [19% buf] [PLAYING @ 7:25/7:31] Welcome to the Machine - Pink Floyd
11/22 20:10:07 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] connected
11/22 20:10:07 Trace: [rnet/RnetJsonClient] SENT {"request":"enumerate_devices","subscription_id":"0"}
11/22 20:10:08 Trace: [streamingmediafile] immediate read of https://streaming2.qobuz.com/file at 98304 length=34378679
11/22 20:10:08 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/307 sec
11/22 20:10:10 Info: [stats] 6774mb Virtual, 1202mb Physical, 497mb Managed, 2457 Handles, 135 Threads
11/22 20:10:12 Trace: [Living Room Pi] [Enhanced, 16/44 QOBUZ FLAC => 32/44] [3% buf] [PLAYING @ 7:30/7:31] Welcome to the Machine - Pink Floyd
11/22 20:10:14 Debug: [smc] [zoneplayer:22] Created domain
11/22 20:10:14 Debug: [smc] [zoneplayer:22] Removing ordinal 9
11/22 20:10:14 Debug: [smc] [zoneplayer:22] Destroyed domain
11/22 20:10:14 Debug: [easyhttp] POST to https://www.qobuz.com/api.json/0.2/track/reportStreamingEnd?
11/22 20:10:14 Info: [zone Living Room Pi] OnPlayFeedback OnToNext
11/22 20:10:14 Debug: [zone Living Room Pi] _Advance
11/22 20:10:14 Info: [library] recorded play for profile bead7847-e39d-49bd-ad2e-2a2800abe97c: mediaid=202:0:47683563 metadataid= contentid=202:0:47683563 libraryid= isfromswim=False
11/22 20:10:14 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
11/22 20:10:14 Debug: [query] Sooloos.Broker.Transport.TransportItem: 5000 dirty items. rebuilding query instead of re-sorting item-by-item (internaltype=TransportItem)
11/22 20:10:14 Debug: GMS: saving nav stack
11/22 20:10:14 Debug: GMS: trying to save nav stack, but nav stack stuff was in progress
11/22 20:10:14 Debug: GMS: trying to save nav stack, but nav stack stuff was in progress
11/22 20:10:14 Debug: [easyhttp] POST to https://www.qobuz.com/api.json/0.2/track/reportStreamingStart?
11/22 20:10:14 Info: [zone Living Room Pi] OnPlayFeedback Playing
11/22 20:10:14 Trace: [library] endmutation in 245ms
11/22 20:10:14 Debug: GMS: done saving nav stack
11/22 20:10:14 Debug: [easyhttp] GET to https://metadata.roonlabs.net/1/tracks/202:0:47683564/lyrics returned after 94 ms, status code: 200
11/22 20:10:14 Debug: [easyhttp] POST to https://www.qobuz.com/api.json/0.2/track/reportStreamingStart? returned after 343 ms, status code: 200
11/22 20:10:14 Debug: [easyhttp] POST to https://www.qobuz.com/api.json/0.2/track/reportStreamingEnd? returned after 640 ms, status code: 200
11/22 20:10:14 Debug: [easyhttp] GET to https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&intent=stream&request_sig=75bcd737e0163c4385226415e6b006d0&request_ts=1574478614&track_id=47683565 returned after 604 ms, status code: 200
11/22 20:10:14 Info: [Living Room Pi] [zoneplayer] Queueing: https://streaming2.qobuz.com/file
11/22 20:10:14 Debug: [smc] [zoneplayer:22] Created domain
11/22 20:10:14 Debug: [smc] [zoneplayer:22] Adding ordinal 11
11/22 20:10:15 Debug: [smc] [zoneplayer:22] Ordinal 11 is good to go
11/22 20:10:15 Info: [Living Room Pi] [zoneplayer] Open result (Queueing): Result[Status=Success]
11/22 20:10:15 Debug: [easyhttp] GET  to https://metadata.roonlabs.net/1/tracks/202:0:47683564/lyrics returned after 45 ms, status code: 304
11/22 20:10:16 Trace: [streamingmediafile] finished caching https://streaming2.qobuz.com/file
11/22 20:10:16 Debug: [smc] [zoneplayer:22] Removing ordinal 11
11/22 20:10:16 Debug: [smc] [zoneplayer:22] Destroyed domain
11/22 20:10:17 Trace: [rnet/RnetJsonClient] no data received for >10000ms. Killing connection.
11/22 20:10:17 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] lost client connection. Retrying
11/22 20:10:17 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] connecting (attempt 1)
11/22 20:10:17 Trace: [Living Room Pi] [Enhanced, 16/44 QOBUZ FLAC => 32/44] [100% buf] [PLAYING @ 0:03/5:07] Have a Cigar - Pink Floyd
11/22 20:10:17 Trace: [raatserver] [RaatServer Caitlins-iPhone @ 192.168.1.17:56396] connected
11/22 20:10:17 Trace: [rnet/RnetJsonClient] SENT {"request":"enumerate_devices","subscription_id":"0"}

[noris]

Hello @Neil_Small,

The log file looks like the track completed until the end without issue and then it started playing Have a Cigar as expected. I am noticing one strange thing in the log file you posted though which is that it appears that the SONOS got a disconnected message around the same time. If you try playing individually to just the RPi zone, do you notice any further issues occur?

[Neil_Small]

The Sonos is in my daughter’s room, and I have no idea if she had issues (kids don’t say…).

I’d ->really<- rather you saw the entire log file(s) - I can only guess what is an error and what isn’t. Since I can’t listen to music during the work week, I’ll be able to give you better feedback this holiday weekend. We plan on a lot of listening, and if there’s an issue, I’ll let you know.

If you’d like the log files, just let me know. There was two skips. “Have A Cigar” played for about 30 seconds (if I remember correctly), and then skipped to “Wish You Were Here”. There’s no doubt about this error. The next night, I had problems with a Miles Davis album.

Cheers,

Neil

[noris]

Hi @Neil_Small,

I’d ->really<- rather you saw the entire log file(s) - I can only guess what is an error and what isn’t. Since I can’t listen to music during the work week, I’ll be able to give you better feedback this holiday weekend. We plan on a lot of listening, and if there’s an issue, I’ll let you know.

Sure, do let me know if you have further issues. If you want to send the full log set, you can do so via dropbox / google drive and share it via link here.

If you have further issues, please note the track and the exact local time you experience the issue, after we can cross-reference in logs to see if there are additional clues. Thanks!

[Neil_Small]

Noris, 10:05am and the song just skipped. Noy my imagination, my wife asked “why’d you skip the song?”.

This album (Carpenters Gold Greatest Hits) is on my NAS.

Please let me know if you want me to (save) get you the log.

[Neil_Small]

I checked with my daughter, and she “yes, the song skipped! Didn’t you hear me ask ‘who changed my music’?”

It’s too bad you (Roon) can’t reproduce the issue, 'cause there are many of us discussing the skipping issues in Facebook audio groups. It is definitely a problem. Thanks for taking interest.

[john (John Iburg)]

Hello @Neil_Small,

As mentioned, we shipped the Roon build 505 update with a few fixes that have improved the “track skipping” situation for the large majority of our users. We continue to investigate all cases of track skipping, as we would like to be known as “The Music Player For Music Lovers”, not “The Music Player That Randomly Skips Tracks”.

The easiest and quickest way to get us logs would be to use a Dropbox or Google Drive shared link, with the “Logs” folder included in a .zip archive. Paste the share link in this thread and I will pass it to the QA team for analysis.

For context,

A) Have you noticed any differences or improvements with the Roon build 505 update?
B) Does the issue occur more or less often on your Raspberry Pi zones verses the Sonos zones?

I would also be interested to see if limiting the bit depth of your Raspberry Pi zone to 16bits would improve the situation.

-John

[Neil_Small]

John,

I have not noticed any difference with 505 update.
No difference in skipping issues in any zone, as far as I can tell. However, the Sonos zones don’t get used as often.

I have zipped up the log files. I hope they reveal something, as I just shut core down and did a cold boot. It was skipping albums when Radio too over.

I can’t share a Dropbox folder without firing up my VM… and I need an email address. Instead, I’ll put the link on my web server. I will upload the .zip file and add the link here shortly.

[Neil_Small]

John,

Here is the link to tall he log files. You will, of course, want to start with the files dated today. My guess is you will find errors in all the log files, if you know what you’re looking for.
https://www.audiophile.one/other/roon_log.13.zip

Since I just restarted core/windows, if the skipping issue continues, I’ll see if limiting the bit depth to 16 bits helps.

Thanks again for your patience.

[john (John Iburg)]

Hello @Neil_Small,

Just checking in, have you noticed any changes in the behavior of your RPi zones over the last few days?

In the logs you sent us, it appears your Core was still in a busy state post update rescanning your files. While this should not affect the completion of track playback, it could possibly cause instability in some cases. It also greatly increases the amount of noise in the logs, making diagnosis difficult.

-John

[Neil_Small]

Sunday morning, several songs after Roon Radio took over, it started skipping albums again. By “skipping albums”, I mean when I’m looking at my iPhone screen to see what was playing (which is why Radio is so awesome), Core suddenly started going through (4? 5?) albums faster than I could read what they were. When it finally stopped, it wouldn’t play. I killed Core. shut down, and did a cold boot. That fixed the problem for Sunday.

Only one track skip that I noticed over the 4 day Thanksgiving Holiday, and it was on Sunday afternoon. If there were others. I didn’t hear them (but the house was noisy at times all weekend). For the most part, It wasn’t an issue. I have a screenshot of the album that skipped, and can get the log file if you want.

I wish I had the time (you can pay me to listen…) to do a lot of listening to see if I can reproduce the environment/settings that are causing this odd behaviour. For now, it will have to be on weekends when Roon is on all weekend.

Thanks for following up.