Build 16 Sorry to be the bringer of bad news, but this version has new problems

Guys, I’m afraid to report that 1.0 build 16 has new problems :frowning:

It started so well - I got through the longest uninterrupted session of AirPlay playing to a single Apple TV2 ever - about 45 minutes! - then a bunch of things happened:

  1. The remote lost the server. Restarting the remote didn’t help - just “Waiting for remote library”. Note: audio was still playing!! Not a connectivity issue - I could screen-share to the server and see it fine.

  2. I started to hear a few audio glitches - thought I was imagining it to start with, but then I heard a few more. Very short breaks or clicks in the audio.

  3. After the next track, audio stopped completely. I went to look at the server - Roon was still there, there was a TIDAL account error popup, and all AirPlay devices had disappeared - even though iTunes could still see them. It was asking me to setup my first audio zone (which covers the area where the current playlist button would be, so I couldn’t check that).

  4. And the server (top Retina MBP) was very busy - roon using 120% cpu, but not visibly doing anything

  5. When I restart the remote, it now always tells me “waiting for remote library” forever, BUT if I look in the local log file, I can see all kinds of server output - so it is communicating, but not telling the UI! Something very wrong here.

The only thing I haven’t yet done is restart the server. That’s next.

@danny @brian @mike I know you guys are working flat out. But this must be the simplest of setups - just 2 modern Retina MBPs and an AppleTV 2, playing a mixture of local and TIDAL content (at the time everything started to go wrong I think it was TIDAL content). Please help! Thank you.

Remote errors as follows (and server errors shown afterwards):

06/03 21:35:51 Warn: [remoting] connection received no data for 12799ms. Assuming dead.
06/03 21:35:51 Info: [brokerclient] Connection dropped: Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101
06/03 21:35:52 Info: [brokerclient] connecting to Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101 (attempt 1/6)
06/03 21:35:52 Info: [client/remoteaudio] Update enabled state
06/03 21:35:52 Info: [client/remoteaudio] ==> disable
06/03 21:35:52 Info: [client/remoteaudio] disabling
06/03 21:35:52 Debug: [brokerclient] auth with Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8): Attempting to authenticate with no PIN
06/03 21:35:52 Trace: SENT REQUEST DistributedBroker.ConnectRequest={ ClientBrokerId=79d00185-7d28-405a-9c7f-7d96d5bb55d6 ClientBrokerName=‘Pauls-MacBook-Pro-Retina-BB’ ProtocolVersion=‘22’ ProtocolHash=‘810a7c38a6e5be0294ab2801d2b96f1c30a23153’ }
06/03 21:35:53 Trace: [library] endmutation in 848ms
06/03 21:35:54 Trace: [library] endmutation in 821ms
06/03 21:35:54 Trace: [library] endmutation in 815ms
06/03 21:35:55 Trace: [library] endmutation in 821ms
06/03 21:35:56 Trace: [library] endmutation in 800ms
06/03 21:35:57 Info: [stats] 2394mb Virtual, 1223mb Physical, 337mb Managed, 50 Threads, 298 FDs (241 REG, 31 IPv4, 10 DIR, 7 KQUEUE, 4 CHR, 3 PIPE, 1 systm, 1 unix)
06/03 21:35:57 Trace: [library] endmutation in 853ms
06/03 21:35:58 Trace: [library] endmutation in 787ms
06/03 21:35:59 Trace: [library] endmutation in 796ms
06/03 21:35:59 Trace: [library] endmutation in 794ms
06/03 21:36:02 Warn: [remoting] connection received no data for 10004ms. Assuming dead.
06/03 21:36:02 Info: [brokerclient] Connection dropped: Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101
06/03 21:36:03 Info: [brokerclient] connecting to Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101 (attempt 1/6)
06/03 21:36:03 Debug: [brokerclient] auth with Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8): Attempting to authenticate with no PIN
06/03 21:36:03 Trace: SENT REQUEST DistributedBroker.ConnectRequest={ ClientBrokerId=79d00185-7d28-405a-9c7f-7d96d5bb55d6 ClientBrokerName=‘Pauls-MacBook-Pro-Retina-BB’ ProtocolVersion=‘22’ ProtocolHash=‘810a7c38a6e5be0294ab2801d2b96f1c30a23153’ }
06/03 21:36:12 Info: [stats] 2394mb Virtual, 1225mb Physical, 354mb Managed, 50 Threads, 290 FDs (241 REG, 24 IPv4, 9 DIR, 7 KQUEUE, 4 CHR, 3 PIPE, 1 systm, 1 unix)
06/03 21:36:13 Warn: [remoting] connection received no data for 10003ms. Assuming dead.
06/03 21:36:13 Info: [brokerclient] Connection dropped: Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101
06/03 21:36:13 Info: [brokerclient] connecting to Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101 (attempt 1/6)
06/03 21:36:14 Debug: [brokerclient] auth with Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8): Attempting to authenticate with no PIN
06/03 21:36:14 Trace: SENT REQUEST DistributedBroker.ConnectRequest={ ClientBrokerId=79d00185-7d28-405a-9c7f-7d96d5bb55d6 ClientBrokerName=‘Pauls-MacBook-Pro-Retina-BB’ ProtocolVersion=‘22’ ProtocolHash=‘810a7c38a6e5be0294ab2801d2b96f1c30a23153’ }
06/03 21:36:24 Warn: [remoting] connection received no data for 10004ms. Assuming dead.
06/03 21:36:24 Info: [brokerclient] Connection dropped: Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101
06/03 21:36:24 Info: [brokerclient] connecting to Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8) @ 192.168.1.105:9101 (attempt 1/6)
06/03 21:36:24 Debug: [brokerclient] auth with Pauls-MacBook-Pro-Retina (e369b878-bc28-48f1-8556-e57b800c65e8): Attempting to authenticate with no PIN
06/03 21:36:24 Trace: SENT REQUEST DistributedBroker.ConnectRequest={ ClientBrokerId=79d00185-7d28-405a-9c7f-7d96d5bb55d6 ClientBrokerName=‘Pauls-MacBook-Pro-Retina-BB’ ProtocolVersion=‘22’ ProtocolHash=‘810a7c38a6e5be0294ab2801d2b96f1c30a23153’ }

Server showing lot of TIDAL errors just before - like this:
06/03 21:35:05 Warn: [tidal/http] https://api.tidalhifi.com/v1/users/26333182/favorites/albums?countryCode=GB&sessionId=85bb28a2-48fb-4805-8c0b-104826d5564b failed: 404
06/03 21:35:05 Warn: [tidal/http] {“status”:404,“subStatus”:2001,“userMessage”:“Playlist not found”}
06/03 21:35:05 Warn: [tidal/storage] failed to add album 166:0:37091210

then some AirPlay errors, like this:

06/03 21:36:22 Trace: [transport/airplay] expired device AirPlayDevice[DeviceId=5855CA037301@Family Room Apple TV._raop._tcp.local, Name=Family-Room-Apple-TV-2.local, IPEndPoint=192.168.1.207:5000] because it isn’t connected and hasn’t been seen in 65s
06/03 21:36:22 Trace: [transport/airplay] expired device AirPlayDevice[DeviceId=EC66D107F484@Z2 7F484._raop._tcp.local, Name=Z2-7F484.local, IPEndPoint=192.168.1.164:1024] because it isn’t connected and hasn’t been seen in 65s
06/03 21:36:22 Trace: [transport/airplay] expired device AirPlayDevice[DeviceId=7CD1C3C59511@Kitchen AirPort Express._raop._tcp.local, Name=Kitchen-AirPort-Express.local, IPEndPoint=192.168.1.206:5000] because it isn’t connected and hasn’t been seen in 65s
06/03 21:36:22 Info: [transport] destroyed zone Family Room
06/03 21:36:22 Info: [transport] destroyed zone Bedroom
06/03 21:36:22 Info: [transport] destroyed zone Kitchen

It appears that 3 totally different subsystems broke at the same time, with completely unrelated networking code and unrelated connections. TIDAL, Airplay, and Roon Remote/Core.

This points to network badness.

As for your CPU, I’m curious as to what is going on. We work pretty hard to be nice to your CPU, but 3 big things impact it:

  1. audio analysis. you can turn if off: settings -> setup -> audio analysis speed -> off), it may help a bit. “normal” should only use 5-10% of your CPU. “fast” uses a ton more.

  2. downsampling. Our downsampler, made by Meridian, is on the cutting edge of DSP technology, and arguably one of the best in the business. It requires a bit more horse power than other solutions out there, but the sound quality is awesome. You can see if it is being activated in the signal path popup… it only should be there if you are requiring a downsampling.

  3. importing. If you have a spinning circle in the upper right of your Roon window, next to bookmarks, you can click on it and see what’s going on. The import procedure is usually limited by the I/O capabilities of your hard drive, but if you have a fast SSD that can keep up, we will use more CPU. Once importing has slowed, you shouldn’t be using a lot of CPU.

Can you investigate these 3 items and see if any of this applies?

There is also a known bug about radio triggering CPU… can you try going to the queue and hitting X near the radio, and restarting? This bug is really hard to trigger, so I’d be shocked if you are running into it.

How many tracks do you have in you library?

Also @pcwilliams, the log you dumped shows a over 60 second outage of the network. It does not show the times where you state that you could screen share but we could not connect.

i don’t think it was a network outage. The AirPlay audio continued to play after the remote said it lost the server. But as I said, when I restarted the remote it could find the server according to the remote logs, but could not show the UI. And the server has not been able to find the AirPlay devices since - even though iTunes can.
iTunes doesn’t suffer any of these problems on my setup.

that says no tcp and no mDNS

My Roon has 3147 albums and 34225 tracks, including the TIDAL albums I have “added”.
Audio analysis was set to normal. Down sampling wasn’t happening - this was ALAC and TIDAL content playing over AirPlay.

No reason why a wired network would fail at that point. And even if it did, Roon could not recover - even now, nearly two hours later, iTunes can see the AirPlay devices but Roon can’t - running on the same machine. This points to a problem in Roon, in my opinion.
Roon server is still busy - 847 threads running, using 120% cpu. Seems like a high number of threads, don’t you think?
I’ve just restarted Roon server and it found the AirPlay devices immediately , and how only has 50 threads and 6% cpu. So this must have been Roon getting into a bad state.
I’m afraid I can’t spend any more time troubleshooting right now. Maybe tomorrow. To be honest I think AirPlay needs a lot more testing. Sorry.

ok wow, thats some real info… the stuff above points to 50 threads, not 847

i think your 847 problem came later… thats definitely us… you are debugging too much already… just send us logs and let us debug :smile:

pcwilliams-please-help-me.zip on your upload server. logs from the server today

Are you running on an SSD or spinning disks?

SSD on both server and remote. The smb mount is a spinning disk on another Mac.
Regarding the thing that looked like a network outage on the server, rather I think the Roon process lost the ability to talk to the network layer properly - which could perhaps explain why it affected multiple systems inside Roon. Maybe something to do with the 800 threads?

lost the ability to talk to the network is a weird concept in unix

i was thinking maybe something was flooding the network, but that wouldnt explain tcp drops

we have this swim related bug we know of, but youd have to pick radio on all your albums at once, and maybe it oculd happen with 3k albums, but its more obvious with 10k and really bad with spinning disks vs ssd

I haven’t used radio. Generally I switch it off - but to be honest it’s rare I’ve got to the end of a playlist before it having an issue :frowning: - so I don’t think radio is a factor unless that is all going on in the background anyway.
If you want to give me a build that has all the clever stuff disabled (radio, tidal, all metadata services, etc etc) I could see if I can get uninterrupted and stable AirPlay streaming. That’s the fundamental thing that makes Roon usable or not for me

do you have start radio automatically turned off?

I thought I did, but I can’t remember with this latest Mac I tried to set the server up on. I can check tonight (on way to work now). Why don’t you output all settings at the top of each log file?

Looking around the forum, looks like @stevev1 is also having similar problems to me with 1.0 build 16. Only difference is that my content is not being downsampled. I definitely ran into the same issue where Roon lost all AirPlay devices forever (until a restart of the app, when they came back immediately)

Any ideas @danny, @brian? You got some nice Airplay fixes for me to try? Happy to be a beta tester if it helps, as long as no-one tells my wife I’ve already paid for this :smile: