Grouped zone playback drops at track transitions with 5 RAAT endpoints (ref#ESU1GA)

Cory_Kim · February 27, 2026, 11:23pm

Hi! What’s not quite right with Roon?

· None of the above quite fits

None of the above quite fits

· None of these quite match

Tell us what's going on

· Grouped zone playback consistently drops out at track transitions when 5 RAAT endpoints are grouped together. Individual playback to each endpoint is stable for hours. The issue is reproducible and occurs multiple times per listening session.

Tell us about your home network

· Network

UniFi UXG Lite gateway
UniFi US-16-PoE 150W switch
3x UniFi APs (2 wired, 1 mesh)
All RAAT endpoints on the same VLAN/subnet (10.0.0.0/16)
IGMP Snooping enabled, mDNS enabled, Multicast to Unicast enabled on WiFi
Mix of wired and WiFi endpoints (WiFi endpoints on dedicated 2.4 GHz SSID)

I've compiled a Full Bug Report

vadim · March 2, 2026, 12:00pm

Hey @Cory_Kim

Welcome to the community, Cory!

Thank you for this exceptionally detailed bug report. It is rare to see such a high level of technical analysis, and the stack traces you’ve provided are very illuminating regarding the SharedObject.Read() exception.

Before we dive deeper into the threading behavior of the zone player, we need to address a few foundational points to stabilize the environment for official support:

As you may be aware, Roon does not officially support Docker installations, including the Unraid container setup you are using. While we recognize your hardware (i5-13600K) is more than capable, the virtualization of the networking stack and thread scheduling in Docker can introduce variables that are difficult to account for in RAAT synchronization.

To rule out the container environment as the culprit, are you able to reproduce this issue using a supported configuration (e.g., a native RoonServer installation on a standard Ubuntu/Windows/macOS partition or a dedicated ROCK NUC)?

When 5 zones are grouped, Roon’s clock synchronization is only as stable as the most “difficult” endpoint in that group.

Have you tried testing smaller groups (e.g., 2 or 3 endpoints) to see if a specific pair or a specific DAC (like the DragonFly or the NuForce) triggers the dropout?
If you remove the WiFi-based endpoints and only group the fully wired ones, does the issue persist?
Please remove the one endopint at the time and isolate the problematic one.

Since the failure occurs specifically at track transitions (where sample rates or clock headers often change), have you tried adding a Resync Delay?

This gives the DACs and the RAAT buffer more time to “settle” during the transition before the stream starts, which often prevents the race condition you are seeing in the logs.

Please try the Resync Delay first, as that is the most common fix for transition-based dropouts. If that fails, please try to reproduce the issue on a supported (non-Docker) setup.

Once you have a reproduction on a supported setup, please provide a fresh timestamp (Date and Time) so our engineering team can look at the diagnostics without the “noise” of the Docker environment.

We look forward to your findings!

Cory_Kim · March 2, 2026, 10:19pm

Thank you for your response. I will attempt the following:

Try Resync Delay on the existing setup
Install Roon Server directly on the OS of a PC that has a hard ethernet connection and sufficient CPU and RAM.

Also, in response to your questions:

I have successfully used Roon with two RAAT endpoints with no trouble, as long as the music files are limited to my local library.
I only have two endpoints with hard ethernet connections, but again with two endpoints I have no problems.
I can play a separate stream to each endpoint without any trouble, even with all five at the same time.

benjamin · March 3, 2026, 7:43pm

Thanks @Cory_Kim, certainly let us know how the above tests go!

Cory_Kim · April 3, 2026, 8:12pm

A couple of weeks ago, I posted an issue about grouped zone playback. Since my last report, I’ve systematically eliminated environmental variables and can now reproduce the issue in a minimal configuration.

Previous setup (when first reported):

Roon Server running in Docker
Multiple grouped zones (3+)
Mix of wired and WiFi endpoints

Current setup (issue persists):

Roon Server 2.60 (build 1501) installed directly on host OS (Ubuntu, bare metal)
Only two zones grouped
Both zones on wired ethernet
One zone is the Roon Server itself (HDA Intel PCH, Denon AVR via HDMI)
Second zone is a wired NUC running RoonBridge (irDAC II via USB)
Both machines are Intel mini-PCs with ample CPU and RAM

The issue: Playback intermittently stops at track boundaries in grouped zones. It does not occur with single zones. The Resync Delay workaround was previously suggested, but I cannot use it because I listen to gapless albums.

The server log consistently shows the same failure pattern. Here is a representative excerpt from today:

04/03 20:00:04 Warn: [Den + Study] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:04 Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread[Id=152, Name=Worker (9)]
at Sooloos.Concurrency.SharedObject2.Read[U](Func2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<_Dispatch>b__0(Object )

This same InvalidOperationException fires simultaneously on multiple worker threads for each endpoint in the group. The SharedObject.Read() call in ev_too_many_dropouts is being invoked without the calling thread holding access, which causes the exception and kills the stream.

Key observations:

The bug followed the server from Docker to bare metal — it is not container-related.
It reproduces with only two grouped zones — it is not a scaling issue.
One of the two zones is the server’s own local audio output — this eliminates network as a factor.
Both endpoints report dropout samples equal to exactly one second of audio (44100 samples at 44.1kHz), suggesting the server-side feed stalls for a full second at track transitions.
Single-zone playback is unaffected.
AirPlay 2 grouped playback (via shairport-sync on the same endpoints) does not exhibit this issue.

I believe this is a threading/concurrency defect in the RAAT grouped zone player’s track transition handling. I’m happy to provide full logs, reproduce on demand, or test any patches.

Thank you.

Cory_Kim · April 3, 2026, 8:17pm

Here is more complete log excerpt:

04/03 20:00:04 \[Local 04/03 15:00:04\] Trace: \[HDA Intel PCH DENON-AVR\] \[raatclient\] GOT \[1099\] {“status”:“Dropout”,“samples”:44100}
04/03 20:00:04 \[Local 04/03 15:00:04\] Warn: \[Den + Study\] \[zoneplayer/raat\] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:04 \[Local 04/03 15:00:04\] Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread\[Id=152, Name=Worker (9)\]
at System.Environment.get_StackTrace()
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
at ThreadUtil.\_WorkerThread()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
04/03 20:00:04 \[Local 04/03 15:00:04\] Trace: \[irDAC II\] \[raatclient\] GOT \[5614\] {“samples”:44100,“status”:“Dropout”}
04/03 20:00:04 \[Local 04/03 15:00:04\] Warn: \[Den + Study\] \[zoneplayer/raat\] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:04 \[Local 04/03 15:00:04\] Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread\[Id=38, Name=Worker (11)\]
at System.Environment.get_StackTrace()
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
at ThreadUtil.\_WorkerThread()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
04/03 20:00:05 \[Local 04/03 15:00:05\] Trace: \[HDA Intel PCH DENON-AVR\] \[raatclient\] GOT \[1099\] {“status”:“Dropout”,“samples”:44100}
04/03 20:00:05 \[Local 04/03 15:00:05\] Warn: \[Den + Study\] \[zoneplayer/raat\] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:05 \[Local 04/03 15:00:05\] Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread\[Id=61, Name=Worker (10)\]
at System.Environment.get_StackTrace()
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
at ThreadUtil.\_WorkerThread()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
04/03 20:00:05 \[Local 04/03 15:00:05\] Trace: \[irDAC II\] \[raatclient\] GOT \[5614\] {“samples”:44100,“status”:“Dropout”}
04/03 20:00:05 \[Local 04/03 15:00:05\] Warn: \[Den + Study\] \[zoneplayer/raat\] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:05 \[Local 04/03 15:00:05\] Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread\[Id=30, Name=Worker (8)\]
at System.Environment.get_StackTrace()
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
at ThreadUtil.\_WorkerThread()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
04/03 20:00:05 \[Local 04/03 15:00:05\] Trace: \[HDA Intel PCH DENON-AVR\] \[raatclient\] GOT \[1099\] {“status”:“Dropout”,“samples”:44100}
04/03 20:00:05 \[Local 04/03 15:00:05\] Warn: \[Den + Study\] \[zoneplayer/raat\] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:05 \[Local 04/03 15:00:05\] Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread\[Id=71, Name=Worker (3)\]
at System.Environment.get_StackTrace()
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
at ThreadUtil.\_WorkerThread()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
04/03 20:00:05 \[Local 04/03 15:00:05\] Trace: \[irDAC II\] \[raatclient\] GOT \[5614\] {“samples”:45864,“status”:“Dropout”}
04/03 20:00:05 \[Local 04/03 15:00:05\] Warn: \[Den + Study\] \[zoneplayer/raat\] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/03 20:00:05 \[Local 04/03 15:00:05\] Critical: threadpoolsynchronizationcontext: System.InvalidOperationException: Attempted to Read() without access in Thread\[Id=164, Name=Worker (1)\]
at System.Environment.get_StackTrace()
at Sooloos.Concurrency.SharedObject`2.Read[U](Func`2 getval)
at Sooloos.Broker.Transport.RaatZonePlayer.ev_too_many_dropouts(Endpoint endpoint)
at Sooloos.Broker.Transport.RaatZonePlayer.Endpoint.OnDropout(Int32 frames)
at Sooloos.ThreadPoolSynchronizationContext.<>c__DisplayClass14_0.<\_Dispatch>b__0(Object )
at ThreadUtil.\_WorkerThread()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)

Cory_Kim · April 3, 2026, 8:21pm

Also, would it be possible to get early access to the Docker distribution of the upcoming 4/20 release? I would love to test that.

Suedkiez · April 3, 2026, 8:33pm

It will be announced in Early Access when available:

You can click here to subscribe to new announcements:

I have also flagged this thread here for the mods so that they can reopen your support thread and merge this thread so that all info is together

alex_h · April 8, 2026, 12:21pm

Hello @Cory_Kim ,

Thanks for reaching us back.

Yes, in your case we’d recommend you to wait until Apr 20, make backup and apply for Early Access program to test out the Docker support we are going to implement soon.

For more details on how to apply for Early access please find here:

.

Thanks for your cooperation.

Andrew_Embury · April 20, 2026, 7:48am

Ive been struggling with the exact same scenario as Cody - everything he described fits my situation as well. Same threading errors in the logs, which are , uh, verbose. I’ve been in IT for almost 30 years and have never seen logs as crazy as Roon’s. The signal-to-noise ratio with the roon logs make it really hard to use them.

Im also convinced that the issue is in Roon’s software as I’ve had smokeping monitoring the paths between the endpoints and the server (dedicated NUC10/32GB) and there is no decrease in speed, latency, jitter, or network reachability during the Roon drops. I’m getting some tcpdump captures now to try to see if anything else shows up in there. I’d also be interested in running via Dockerl but I’m not sure what good thats going to do if the issue is software…

Cory_Kim · April 20, 2026, 7:16pm

I’m glad I’m not the only one! BTW, WRT docker: I prefer to run Roon on my Unraid NAS that has all of the music files (3.2 TiB), and this will help to eliminate NFS / SMB as possible causes.

noris · April 27, 2026, 7:01pm

Hello @Cory_Kim ,

The latest Roon release is out now, when you have a chance to update, please let us know if you notice any performance improvements, thanks!

Cory_Kim · April 27, 2026, 11:07pm

Thanks for checking in. I’ve been testing the Docker version with v 2.65 (build 1654) since last night. I was able to run two wired endpoints in a grouped zone with no troubles. I am now trying a larger zone with five endpoints, three wired and two wireless. We’ll see how that goes!

Cory_Kim · April 30, 2026, 7:05pm

@noris I’ve tested the new version and have good news and bad news. The concurrency issue seems to have resolved, but it appears that this has unmasked a deeper root cause. I am able to reproduce this problem using the official Docker early-access install, and today’s current installation using the easy installation script for Linux, directly on a host OS.

In both cases, all three endpoints are wired with physical ethernet, with 1 Gbps links throughout.

Previously, the Roon Server would stop playing at track boundaries. Now the server stops exactly three seconds after a track boundary. It seems to think that it has successfully recovered afterwards, but the clients no longer receive a stream and remain stuck at the “0:03” time marker.

I’ve attached a relevant log snipped from the bare-metal roonserver, and an analysis generated by Claude below:

Setup:

Roon Server 2.60 (build 1501), tested both in Docker (on Unraid) and installed directly on host OS (Ubuntu, bare metal)
Three grouped zones: Den (server’s own local output, HDA Intel PCH / Denon AVR), Study (wired NUC, irDAC II), Living Room (wired NUC, NuForce µDAC 2)
All devices on wired ethernet
Source material: TIDAL hi-res FLAC (24/176, 24/96)
The issue is identical across both Docker and bare metal — it is not container-related

The issue: Playback intermittently stops at track boundaries in grouped zones. Single-zone playback is not affected. Resync Delay is not a viable workaround because I listen to gapless albums.

I’ve identified two problems from the server logs:

PROBLEM 1: Pre-buffer drains before track transition

The server does not pre-buffer the next track aggressively enough for hi-res TIDAL content in grouped zones. Here is what the logs show leading up to a failure:

18:46:04 [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [49% buf] [PLAYING @ 2:31/2:41] Walk On - Neil Young
18:46:09 [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [PLAYING @ 2:36/2:41] Walk On - Neil Young
18:46:14 [irDAC II] [raatclient] GOT [2604] {“samples”:58100,“status”:“Dropout”}
18:46:14 [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {“samples”:57756,“status”:“Dropout”}
18:46:14 [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {“samples”:15652,“status”:“Dropout”}

The buffer drops from 49% to 3% in five seconds. When the track ends, all three endpoints starve simultaneously while the server resolves the next track from TIDAL (playback authorization, metadata, album art, lyrics — approximately 15 HTTP requests all within the same second). The endpoints report one second of dropout samples each cycle (~88200 at 88.2kHz, ~22050 for the downsampled output), and after 3 seconds the dropout threshold kills the stream:

18:46:17 Warn: [Den + Study + Living Room] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream

This pattern is identical across Docker and bare metal. The server’s own local output (HDA Intel PCH) starves just the same as the remote endpoints, eliminating network as a factor.

PROBLEM 2: Recovery fails due to internal state confusion

After the dropout kills the stream, the server actually recovers — it successfully tears down, re-sets up all endpoints at the new sample rate (24/96), syncs clocks, and reaches Playing state on all three endpoints by 18:46:19. However, during the dropout cascade, the server logs:

18:46:17 Info: [Den + Study + Living Room] [zoneplayer] BufferingTrack == NextTrack during ClearQueuedMedia, setting _stop_on_next_track_transition

Three seconds after the successful recovery:

18:46:22 [zone Den + irDAC II + NuForce µDAC 2 USB Audio] [zone] no playback for 5s, suspending to release audio device

The server suspends playback at 0:03 into the new track despite all endpoints being in Playing state. The _stop_on_next_track_transition flag set during the confused dropout recovery appears to cause the server to kill its own successfully recovered playback.

Summary:

The pre-buffer for the next track drains to near-zero before the track transition completes, especially with hi-res TIDAL content in grouped zones
All grouped endpoints starve simultaneously during the TIDAL API resolution window (~1-2 seconds), triggering the 3-second dropout threshold
Even when the server successfully recovers and restarts the new track, internal state confusion causes it to immediately suspend playback again

I previously reported a threading bug (System.InvalidOperationException: Attempted to Read() without access in SharedObject.Read() within ev_too_many_dropouts) which appears to have been fixed in this build — thank you. However, the underlying feed stall and the recovery state issue remain.

I’m happy to provide complete logs, reproduce on demand, or test any patches. Would it be possible to have an engineer review the grouped zone pre-buffering behavior and the _stop_on_next_track_transition logic?

Thank you.

Cory_Kim · April 30, 2026, 7:11pm

04/30 18:18:46 [Local 04/30 13:18:46] Trace: [Den] [Lossless, 24/192 FLAC => 24/192] [100% buf] [PLAYING @ 0:14/3:34] All I Want - Joni Mitchell
04/30 18:18:46 [Local 04/30 13:18:46] Trace: [Study] [Lossless, 24/192 FLAC => 24/192] [100% buf] [PLAYING @ 0:14/3:34] All I Want - Joni Mitchell
04/30 18:18:46 [Local 04/30 13:18:46] Trace: [Living Room] [HighQuality 44.5x, 24/192 FLAC => 24/48] [100% buf] [PLAYING @ 0:14/3:34] All I Want - Joni Mitchell
04/30 18:18:46 [Local 04/30 13:18:46] Trace: [storage] [directory] timer delay: 3840000, retrycount: 8
04/30 18:46:00 [Local 04/30 13:46:00] Debug: FTMSI-B-OE ti/C0253D89 rid:1 interrupt requested; reason: exit
04/30 18:46:00 [Local 04/30 13:46:00] Debug: FTMSI-B-OE ti/C0253D89 rid:1 request ended -- first block: 0 blocks read: 6895 download speed: 12002kbps response time: 130ms
04/30 18:46:00 [Local 04/30 13:46:00] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:00 [Local 04/30 13:46:00] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:02 [Local 04/30 13:46:02] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:02 [Local 04/30 13:46:02] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [49% buf] [PLAYING @ 2:31/2:41] Walk On - Neil Young
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Study] [Lossless, 24/176 TIDAL FLAC => 24/176] [49% buf] [PLAYING @ 2:31/2:41] Walk On - Neil Young
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Living Room] [HighQuality 38.7x, 24/176 TIDAL FLAC => 24/44] [49% buf] [PLAYING @ 2:31/2:41] Walk On - Neil Young
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync HDA Intel PCH DENON-AVR: realtime=47743321923048 rtt=77us offset=42299895876us delta=13us drift=-47us in 151.9542288s (-0.316ppm, -1.137ms/hr)
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio: realtime=44528390729304 rtt=253us offset=39084963402us delta=-96us drift=-428us in 151.9553665s (-2.817ppm, -10.142ms/hr)
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II: realtime=45126150187059 rtt=248us offset=39682722111us delta=-46us drift=-7126us in 151.9560206s (-46.901ppm, -168.843ms/hr)
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:04 [Local 04/30 13:46:04] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:05 [Local 04/30 13:46:05] Info: [stats] 37119mb Virtual, 3615mb Physical, 1765mb Managed, 1850mb estimated Unmanaged, 576 Handles, 79 Threads, 1.55% of runtime in GC pauses, 15ms last GC pause duration
04/30 18:46:06 [Local 04/30 13:46:06] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:06 [Local 04/30 13:46:06] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:08 [Local 04/30 13:46:08] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:08 [Local 04/30 13:46:08] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:09 [Local 04/30 13:46:09] Trace: [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [PLAYING @ 2:36/2:41] Walk On - Neil Young
04/30 18:46:09 [Local 04/30 13:46:09] Trace: [Study] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [PLAYING @ 2:36/2:41] Walk On - Neil Young
04/30 18:46:09 [Local 04/30 13:46:09] Trace: [Living Room] [HighQuality 38.7x, 24/176 TIDAL FLAC => 24/44] [3% buf] [PLAYING @ 2:36/2:41] Walk On - Neil Young
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":58100,"status":"Dropout"}
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"samples":57756,"status":"Dropout"}
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":15652,"status":"Dropout"}
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":88207,"status":"Dropout"}
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"samples":88200,"status":"Dropout"}
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":22050,"status":"Dropout"}
04/30 18:46:14 [Local 04/30 13:46:14] Trace: [Living Room] [HighQuality 23.0x, 24/176 TIDAL FLAC => 24/44] [3% buf] [PLAYING @ 2:40/2:41] Walk On - Neil Young
04/30 18:46:15 [Local 04/30 13:46:15] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":88208,"status":"Dropout"}
04/30 18:46:15 [Local 04/30 13:46:15] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"samples":88200,"status":"Dropout"}
04/30 18:46:15 [Local 04/30 13:46:15] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":22050,"status":"Dropout"}
04/30 18:46:15 [Local 04/30 13:46:15] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":88208,"status":"Dropout"}
04/30 18:46:15 [Local 04/30 13:46:15] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"samples":88200,"status":"Dropout"}
04/30 18:46:15 [Local 04/30 13:46:15] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":22050,"status":"Dropout"}
04/30 18:46:16 [Local 04/30 13:46:16] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":88207,"status":"Dropout"}
04/30 18:46:16 [Local 04/30 13:46:16] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"samples":88200,"status":"Dropout"}
04/30 18:46:16 [Local 04/30 13:46:16] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":22050,"status":"Dropout"}
04/30 18:46:16 [Local 04/30 13:46:16] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":88206,"status":"Dropout"}
04/30 18:46:16 [Local 04/30 13:46:16] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"samples":88200,"status":"Dropout"}
04/30 18:46:16 [Local 04/30 13:46:16] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":22050,"status":"Dropout"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [irDAC II] [raatclient] GOT [2604] {"samples":88202,"status":"Dropout"}
04/30 18:46:17 [Local 04/30 13:46:17] Warn: [Den + Study + Living Room] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den + Study + Living Room] [zoneplayer/raat] too many dropouts. stopping stream
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B closed file for ti/112848DA; open files:0
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B ti/112848DA download status: AllBlocksDownloaded accessTimeout:True openFiles:0 prev:(AllBlocksDownloaded,True,1)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [PLAYING @ 2:40/2:41] Walk On - Neil Young
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B closed file for ti/C0253D89; open files:0
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B ti/C0253D89 download status: AllBlocksDownloaded accessTimeout:True openFiles:0 prev:(AllBlocksDownloaded,True,1)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Playing => Prepared
04/30 18:46:17 [Local 04/30 13:46:17] Info: [audio/env] [zoneplayer -> stream] All streams were disposed
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [84]{"request":"end_stream"}
04/30 18:46:17 [Local 04/30 13:46:17] Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/30 18:46:17 [Local 04/30 13:46:17] Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/30 18:46:17 [Local 04/30 13:46:17] Info: [audio/env] [zoneplayer] All streams were disposed
04/30 18:46:17 [Local 04/30 13:46:17] Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/30 18:46:17 [Local 04/30 13:46:17] Info: [library] recorded play for profile 9a13c2b7-8a47-479e-b3f1-f7fd833ed56b: mediaid=168:0:76441191 metadataid= contentid=168:0:76441191 libraryid= isfromradio=True isfrommix=False isfrommobile=
04/30 18:46:17 [Local 04/30 13:46:17] Info:
04/30 18:46:17 [Local 04/30 13:46:17] Info:
04/30 18:46:17 [Local 04/30 13:46:17] Info:
04/30 18:46:17 [Local 04/30 13:46:17] Info: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] OnPlayFeedback StoppedEndOfMediaNatural
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] _Advance (Track)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [82] {"status":"Ended"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [84] {"status":"Success"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [mlradio] [1] [music/mlradio] GetNextItem(1 / 15)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [mlradio] [1] [music/mlradio] returning 1 items for request of 1 items
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] queue got oversized. trimming 1 items from start
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] Remove(1 items, for_replace=False)
04/30 18:46:17 [Local 04/30 13:46:17] Info: after removeall ordered count 8000 shuffle count 8000
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"samples":22050,"status":"Dropout"}
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [raat/tcpaudiosource] disconnecting
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Playing => Prepared
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [irDAC II] [raatclient] SENT [2683]{"request":"end_stream"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [irDAC II] [raatclient] GOT [2604] {"status":"Ended"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [irDAC II] [raatclient] GOT [2683] {"status":"Success"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [LOADING @ 0:00] (I Know) I'm Losing You - Rod Stewart
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Study] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [LOADING @ 0:00] (I Know) I'm Losing You - Rod Stewart
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Living Room] [HighQuality 20.3x, 24/176 TIDAL FLAC => 24/44] [3% buf] [LOADING @ 0:00] (I Know) I'm Losing You - Rod Stewart
04/30 18:46:17 [Local 04/30 13:46:17] Info: ComputeSwimType(LimitToSeed=False, PerformerIds.Count=0, ComposerIds.Count=0)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: GetImageData[Remote](id=137098 spec=256 key=avuhaaaa) => got from cache overalltime=0ms
04/30 18:46:17 [Local 04/30 13:46:17] Trace: GetImageData[Remote](id=137098 spec=256 key=avuhaaaa) => got from cache overalltime=0ms
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [raat/tcpaudiosource] disconnecting
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Playing => Prepared
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2673]{"request":"end_stream"}
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2948] GET to https://api.tidal.com/v1/tracks/93231287/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES_LOSSLESS&assetpresentation=FULL&playbackmode=STREAM returned after 192 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2594] {"status":"Ended"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2673] {"status":"Success"}
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [dbperf] flush 0 bytes, 0 ops in 10 ms (cumulative 575927 bytes, 650 ops in 30310 ms)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 575927 bytes, 650 ops in 30311 ms)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/93231287/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES_LOSSLESS&assetpresentation=FULL&playbackmode=STREAM => Success
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2951] GET to https://api.roonlabs.net/metadata/1/tracks/168:0:93231287/lyrics?tidal=max returned after 143 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [raat/tcpaudiosource] disconnecting
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2950] POST to https://api.roonlabs.net/swim/1/session/c9c2353145464eaab2caaf259f1e7b3b/feedback returned after 217 ms, status code: 200, request body size: 174 B
04/30 18:46:17 [Local 04/30 13:46:17] Trace: GetImageData[Remote](id=137098 spec=512 key=avuhaaaa uri=https://imagecache.roonlabs.net/im/1/albums/a6003933323331323830/cover/512.jpg) => fetched in 140ms status=304 size=0 overalltime=151ms
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2956] GET to https://api.tidal.com/v1/tracks/93231287?countryCode=US returned after 128 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/93231287?countryCode=US => Success
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2954] GET to https://api.roonlabs.net/metadata/1/albums/166:0:93231280/tracks?c=tidal-us&tidal=max returned after 138 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2955] GET to https://api.roonlabs.net/metadata/1/albums/166:0:93231280/credits?c=tidal-us&tidal=max returned after 140 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2953] GET to https://api.roonlabs.net/metadata/1/albums/166:0:93231280?c=tidal-us&tidal=max returned after 145 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Info: sleep 54ms after flush
04/30 18:46:17 [Local 04/30 13:46:17] Info: [Den + Study + Living Room] [zoneplayer] BufferingTrack == NextTrack during ClearQueuedMedia, setting _stop_on_next_track_transition
04/30 18:46:17 [Local 04/30 13:46:17] Warn: [Den + Study + Living Room] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den + Study + Living Room] [zoneplayer/raat] too many dropouts. stopping stream
04/30 18:46:17 [Local 04/30 13:46:17] Info: [Den + Study + Living Room] [zoneplayer] Playing: https://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiRjNjYzZjM0YWYxNDk3YjA2ODRlYmY1YjVlOTA4YTAxMi5tcDQ/0.flac
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B Cache open file ti/C0253D89 domain: zoneplayer:8 ordinal:38
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B ti/C0253D89 download status: AllBlocksDownloaded accessTimeout:True openFiles:1 prev:(AllBlocksDownloaded,True,0)
04/30 18:46:17 [Local 04/30 13:46:17] Info: FTMSI-B FileCache removed ti/112848DA
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B-OE ti/112848DA exit thread signalled
04/30 18:46:17 [Local 04/30 13:46:17] Trace: FTMSI-B 1 FileCache ti/C0253D89 dwStatus:AllBlocksDownloaded files:1 accessTimeOut:True priorities: ('zoneplayer:8':38) --> bw limit:0kbps
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B-OE ti/112848DA exit thread signalled
04/30 18:46:17 [Local 04/30 13:46:17] Info: [Den + Study + Living Room] [zoneplayer]     Open Result (Playing):Result[Status=Success]
04/30 18:46:17 [Local 04/30 13:46:17] Info: [Den + Study + Living Room] [zoneplayer] Aborting play because track changed
04/30 18:46:17 [Local 04/30 13:46:17] Info:
04/30 18:46:17 [Local 04/30 13:46:17] Warn: inactive signal path :(
04/30 18:46:17 [Local 04/30 13:46:17] Info:
04/30 18:46:17 [Local 04/30 13:46:17] Warn: inactive signal path :(
04/30 18:46:17 [Local 04/30 13:46:17] Info:
04/30 18:46:17 [Local 04/30 13:46:17] Warn: inactive signal path :(
04/30 18:46:17 [Local 04/30 13:46:17] Info: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] OnPlayFeedback StoppedEndOfMediaNatural
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] _Advance (Track)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] queue got oversized. trimming 1 items from start
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] Remove(1 items, for_replace=False)
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B closed file for ti/C0253D89; open files:0
04/30 18:46:17 [Local 04/30 13:46:17] Debug: FTMSI-B ti/C0253D89 download status: AllBlocksDownloaded accessTimeout:False openFiles:0 prev:(AllBlocksDownloaded,True,1)
04/30 18:46:17 [Local 04/30 13:46:17] Info: [audio/env] [zoneplayer] All streams were disposed
04/30 18:46:17 [Local 04/30 13:46:17] Info: [metadata/albumdetails] Created album details screen for a6003933323331323830
04/30 18:46:17 [Local 04/30 13:46:17] Info: [metadata/albumdetails] 79004d5730303030313931383930,79004d5230303033373032373931,79004d5230303030323630303135,79004d5230303030303939303335,79004d5230303034393336373933,79004d5230303034323330303830,79004d5230303033373438353331,79004d5230303032393232393937,79004d5230303031303832393635,79004d5230303034333937383437,79004d5230303033303936373135,79004d5230303034383835383030,79004d5230303034363438323637,79004d5230303034353830313539,79004d5230303034323330313032,79004d5230303034323330303434,79004d5230303034303432323235,79004d5230303033333532393032,79004d5230303030393830383538,3e019d158a852182fd46a7397e3214bf6d9d,3e015752257c5a9e0744bde07a291698a88b,3e0188a40912765ab84d92d743cf5218bff7,3e01e0a9c6a324e51746bb01da5f00e00e6b,3e015deba7db90692e4b818496da42fda50d,3e01c1476c697fd43e4f8ffe3e9fb01c9437,3e01f1a33bce9c6d0c4baf7a0c3f7553ed35,3e01b1bb21f4abb5b8459fa79f92a84727a8,3e011dd8bfc6dbe3e23abb09457d56101585,3e01a18c5ac6f3825a439fae88cb7696a561,3e01864c64c427d68f3fa1208d2d35492f00,3e01e83663aee15f9443ad771e742d4ad162,3e01ed913f733a2fd546bac8df739f3d31fc,3e019737f26f3ed00d4286c13cd814f40680,3e016ce7a85a15b6374cbf1608c9b750eb8b,3e011eca4057c933354cb4df9157995a6c32,3e0141b6bc5273315c4e86459fdd4e417d48,3e01b7288d3d07e1fe42bd7b94b39b7bf95d,3e01ea4a8c0798e9294da393a4bf17e47eb2,79004d5230303034303432313837,79004d5230303031303732343733,3e016f1759cd9381704a8d6e4ffcb69c5d69,3e0151b4095e8d480840a0025820a71fe6bb,3e01ab16a43146697041a708aed582d457d0,3e014860542c718b0940914c0e7a42a54f11,a6003933363134313432,a6003933323431313237,a6003933323331323830,a600343231323437343137,c80068787537686879793568643361,c800796e6e706838376a71776c3861,c8006562336f7737686a6c37666b61,cd0044616b73684a46656e5036303179554f7168,cd00482d5238776337356962456355794f385154,cd00437054456f46576b6177375943486966474b,cd002d6f47515a7a3173326a7931773071636143,cd00347375617053755378487339437451597364,cd004f7473756f7963424571624d39365f4a5f69,590038333635343433,590038333636393134,590038333636393132
04/30 18:46:17 [Local 04/30 13:46:17] Info: after removeall ordered count 8000 shuffle count 8000
04/30 18:46:17 [Local 04/30 13:46:17] Info: FTMSI-B FileCache disposed ti/112848DA
04/30 18:46:17 [Local 04/30 13:46:17] Trace: GetImageData[Remote](id=137098 spec=256 key=avuhaaaa uri=https://imagecache.roonlabs.net/im/1/albums/a6003933323331323830/cover/256.jpg) => fetched in 125ms status=304 size=0 overalltime=125ms
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2949] GET to https://api.tidal.com/v1/tracks/49818075/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES_LOSSLESS&assetpresentation=FULL&playbackmode=STREAM returned after 303 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Debug: [easyhttp] [2957] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=174:1:c569769f-4785-3eed-b851-406b3da21030&type=description&sourceLangs=Rovi-albums:en,Wikipedia:en,Rovi-artists:en,Rovi-compositions:en&c=tidal-us&contentPreferences=avoidMqa&tidal=max returned after 269 ms, status code: 200, request body size: 0 B
04/30 18:46:17 [Local 04/30 13:46:17] Info: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] OnPlayFeedback Stopped
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Den] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [STOPPED @ 0:00] Do I Do - Stevie Wonder
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Study] [Lossless, 24/176 TIDAL FLAC => 24/176] [3% buf] [STOPPED @ 0:00] Do I Do - Stevie Wonder
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [Living Room] [HighQuality 20.3x, 24/176 TIDAL FLAC => 24/44] [3% buf] [STOPPED @ 0:00] Do I Do - Stevie Wonder
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [dbperf] flush 0 bytes, 0 ops in 8 ms (cumulative 575927 bytes, 650 ops in 30319 ms)
04/30 18:46:17 [Local 04/30 13:46:17] Trace: GetImageData[Remote](id=154488 spec=256 key=wnuiaaaa) => got from cache overalltime=0ms
04/30 18:46:17 [Local 04/30 13:46:17] Trace: GetImageData[Remote](id=154488 spec=256 key=wnuiaaaa) => got from cache overalltime=0ms
04/30 18:46:17 [Local 04/30 13:46:17] Trace: [mlradio] [1] [music/mlradio] GetNextItem(1 / 14)
04/30 18:46:17 [Local 04/30 13:46:17] Info: [mlradio] [1] CONTINUE(25)

Cory_Kim · April 30, 2026, 7:12pm

04/30 18:46:18 [Local 04/30 13:46:18] Trace: [dbperf] flush 0 bytes, 0 ops in 3 ms (cumulative 575927 bytes, 650 ops in 30322 ms)
04/30 18:46:18 [Local 04/30 13:46:18] Info: [library] recorded play for profile 9a13c2b7-8a47-479e-b3f1-f7fd833ed56b: mediaid=168:0:93231287 metadataid= contentid=168:0:93231287 libraryid= isfromradio=True isfrommix=False isfrommobile=
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/49818075/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES_LOSSLESS&assetpresentation=FULL&playbackmode=STREAM => Success
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2969] GET to https://api.tidal.com/v1/tracks/49818075?countryCode=US returned after 117 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/49818075?countryCode=US => Success
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2963] GET to https://api.roonlabs.net/metadata/1/tracks/168:0:49818075/lyrics?tidal=max returned after 161 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2962] POST to https://api.roonlabs.net/metadata/1/albums/translate?c=tidal-us&tidal=max returned after 162 ms, status code: 200, request body size: 186 B
04/30 18:46:18 [Local 04/30 13:46:18] Info: [library/albumdetails] found 3 streaming service alternates
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2964] GET to https://api.roonlabs.net/metadata/1/albums/166:0:49818059?c=tidal-us&tidal=max returned after 167 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Trace: GetImageData[Remote](id=154488 spec=512 key=wnuiaaaa uri=https://imagecache.roonlabs.net/im/1/albums/a6003439383138303539/cover/512.jpg) => fetched in 155ms status=200 size=77545 overalltime=190ms
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2968] GET to https://api.tidal.com/v1/tracks/49818075/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES_LOSSLESS&assetpresentation=FULL&playbackmode=STREAM returned after 147 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/49818075/playbackinfopostpaywall?countryCode=US&audioquality=HI_RES_LOSSLESS&assetpresentation=FULL&playbackmode=STREAM => Success
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2966] GET to https://api.roonlabs.net/metadata/1/albums/166:0:49818059/credits?c=tidal-us&tidal=max returned after 157 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2965] GET to https://api.roonlabs.net/metadata/1/albums/166:0:49818059/tracks?c=tidal-us&tidal=max returned after 170 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Trace: GetImageData[Remote](id=154488 spec=256 key=wnuiaaaa uri=https://imagecache.roonlabs.net/im/1/albums/a6003439383138303539/cover/256.jpg) => fetched in 162ms status=304 size=0 overalltime=162ms
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2961] POST to https://api.roonlabs.net/swim/1/session/c9c2353145464eaab2caaf259f1e7b3b/feedback returned after 205 ms, status code: 200, request body size: 176 B
04/30 18:46:18 [Local 04/30 13:46:18] Info: [metadata/albumdetails] Created album details screen for a6003439383138303539
04/30 18:46:18 [Local 04/30 13:46:18] Info: [metadata/albumdetails] 79004d5730303030313932343037,79004d5230303030333439303138,79004d5230303030333237383131,79004d5230303034373231333732,79004d5230303034343531353739,79004d5230303033363935353133,79004d5230303032393038323838,79004d5230303035313430363532,79004d5230303031343231333734,79004d5230303031343136313634,79004d5230303033303330363231,3e015d3e6fe02ccd594e9011223082c70069,3e019f461af4cf2c403eb689ea4d297807f3,3e014dcd43ca7124b645a1fe9abdfd5fc359,3e01a7d71ab3177a1b4bb697cf2f74d7f29d,3e01dedcd9873532974fbabf4251be37731e,3e019f010c662b441034bc838291e8624e2c,3e018a7b3d4ae2ff4c4baf3e0ed23e8edddc,3e01a269fc3d3dc5de4ba58d39ee47d5c5f4,3e0152010433b772424bb314a1395883d7e9,3e0112169030d77bc44f956a3fb74051ec5d,3e01db72be202f28754cb9bb92223582ca6e,3e01bc86a308dd2b0545a8eec04995cbf1e9,3e01f541b41e5bba974c8a64a73066e6b432,3e01ddd2909ed99f3e4abafdcd7ff7a3bc16,79004d5230303031333931333338,79004d5230303031333931343236,79004d5230303031323533313437,79004d5230303030353137373937,a6003439383138303539,a600313231353634333937,a6003739343231373331,c800796d6b35347068687938743962,c8007771646f646636636f35306461,c80030303630323533373830393635,cd003559675047427048734c70507a6662796870,cd00585f554f7152636b794b67416b345f4f5a76,59003130363335363639,590034393335303332,590034313732343537
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2971] POST to https://api.roonlabs.net/browse/1/works/trackCounts?c=tidal-us&tidal=max returned after 229 ms, status code: 200, request body size: 2 KB
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2973] GET to https://api.tidal.com/v1/tracks/49818075?countryCode=US returned after 155 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [tidal/http] GET https://api.tidal.com/v1/tracks/49818075?countryCode=US => Success
04/30 18:46:18 [Local 04/30 13:46:18] Info: [Den + Study + Living Room] [zoneplayer] Playing: https://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic5NWI3NWI4N2M1NGU2MWMzNWU0NmUyYTExNGQ3MmYzYV82Mi5tcDQ/0.flac
04/30 18:46:18 [Local 04/30 13:46:18] Info: [Den + Study + Living Room] [zoneplayer] Queueing: /music/general/Simon & Garfunkel/Bridge Over Troubled Water (1970)/10 - Bye Bye Love [CD FLAC 24bit].flac
04/30 18:46:18 [Local 04/30 13:46:18] Info: FTMSI-B new FileCache ti/299D4435
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B Cache open file ti/299D4435 domain: zoneplayer:8 ordinal:39
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B ti/299D4435 download status: DownloadNotStarted accessTimeout:False openFiles:1 prev:no
04/30 18:46:18 [Local 04/30 13:46:18] Info: FTMSI-B ti/299D4435: allocated bw changed from 0 to 51200 kbps
04/30 18:46:18 [Local 04/30 13:46:18] Info: FTMSI-B 1 FileCache ti/C0253D89 dwStatus:AllBlocksDownloaded files:0 accessTimeOut:False priorities: ('zoneplayer:8':38) --> bw limit:0kbps
04/30 18:46:18 [Local 04/30 13:46:18] Info: FTMSI-B 2 FileCache ti/299D4435 dwStatus:DownloadNotStarted files:1 accessTimeOut:False priorities: ('zoneplayer:8':39) --> bw limit:51200kbps
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B-OE ti/299D4435 created new req 1 for block 0 p 4294967295; active requests 1
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2967] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=174:1:3c8b6a81-e11f-44cf-8305-e8f64d889153&type=description&sourceLangs=Rovi-albums:en,Wikipedia:en,Rovi-artists:en,Rovi-compositions:en&c=tidal-us&contentPreferences=avoidMqa&tidal=max returned after 334 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2972] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=121:0:MW0000191890&type=review&sourceLangs=Rovi-albums:en,Wikipedia:en,Rovi-artists:en,Rovi-compositions:en&c=tidal-us&contentPreferences=avoidMqa&tidal=max returned after 340 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Info: [Den + Study + Living Room] [zoneplayer] Open result (Queueing): Result[Status=Success]
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2974] POST to https://api.roonlabs.net/metadata/1/albums/translate?c=tidal-us&tidal=max returned after 152 ms, status code: 200, request body size: 167 B
04/30 18:46:18 [Local 04/30 13:46:18] Info: [library/albumdetails] found 3 streaming service alternates
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [roondns] flushed 10 last-known-good entries
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2978] GET to https://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic5NWI3NWI4N2M1NGU2MWMzNWU0NmUyYTExNGQ3MmYzYV82Mi5tcDQ/0.flac?token=xxxxxx returned after 183 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B got length for ti/299D4435; 223.5 MBytes
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B ti/299D4435 download status: FileLengthRetrieved accessTimeout:False openFiles:1 prev:(DownloadNotStarted,False,1)
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B-OE set min bandwidth for ti/299D4435 to 3498 kbps
04/30 18:46:18 [Local 04/30 13:46:18] Info: FTMSI-B-OE ti/299D4435 rid:1 response took 184ms
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2977] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=191:0:520972&type=biography&sourceLangs=Rovi-albums:en,Wikipedia:en,Rovi-artists:en,Rovi-compositions:en&c=tidal-us&contentPreferences=avoidMqa&tidal=max returned after 204 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Debug: FTMSI-B ti/299D4435 download status: FirstBlockRetrieved accessTimeout:False openFiles:1 prev:(FileLengthRetrieved,False,1)
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [dbperf] flush 0 bytes, 0 ops in 6 ms (cumulative 575927 bytes, 650 ops in 30328 ms)
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2975] POST to https://api.roonlabs.net/browse/1/works/trackCounts?c=tidal-us&tidal=max returned after 254 ms, status code: 200, request body size: 1 KB
04/30 18:46:18 [Local 04/30 13:46:18] Debug: [easyhttp] [2976] GET to https://api.roonlabs.net/metadatatext/1/blobs?objectId=121:0:MW0000192407&type=review&sourceLangs=Rovi-albums:en,Wikipedia:en,Rovi-artists:en,Rovi-compositions:en&c=tidal-us&contentPreferences=avoidMqa&tidal=max returned after 294 ms, status code: 200, request body size: 0 B
04/30 18:46:18 [Local 04/30 13:46:18] Info: [Den + Study + Living Room] [zoneplayer]     Open Result (Playing):Result[Status=Success]
04/30 18:46:18 [Local 04/30 13:46:18] Info: [Den + Study + Living Room] [zoneplayer] Starting playback
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Combining SRC work (StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False) -> StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False)) for 2 devices
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False) => StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False) streamid=697069918
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False) => StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False) streamid=697069918
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=24, samplerate=96000, isdts=False) => StreamFormat(channels=2, bitspersample=24, samplerate=48000, isdts=False) streamid=697069918
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [85]{"request":"teardown"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Prepared => Idle
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [86]{"request":"setup","format":{"sample_type":"pcm","sample_rate":96000,"bits_per_sample":24,"channels":2,"sample_subtype":"none"}}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] SENT [2684]{"request":"teardown"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Prepared => Idle
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] SENT [2685]{"request":"setup","format":{"sample_type":"pcm","sample_rate":96000,"bits_per_sample":24,"channels":2,"sample_subtype":"none"}}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2674]{"request":"teardown"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Prepared => Idle
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2675]{"request":"setup","format":{"sample_type":"pcm","sample_rate":48000,"bits_per_sample":24,"channels":2,"sample_subtype":"none"}}
04/30 18:46:18 [Local 04/30 13:46:18] Info: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] OnPlayFeedback Playing
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den] [Lossless, 24/96 TIDAL FLAC => 24/96] [3% buf] [PLAYING @ 0:00] Do I Do - Stevie Wonder
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Study] [Lossless, 24/96 TIDAL FLAC => 24/96] [3% buf] [PLAYING @ 0:00] Do I Do - Stevie Wonder
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Living Room] [HighQuality 20.3x, 24/96 TIDAL FLAC => 24/48] [3% buf] [PLAYING @ 0:00] Do I Do - Stevie Wonder
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [81] {"status":"Teardown"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] GOT [2603] {"status":"Teardown"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2473] {"status":"Teardown"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2675] {"message":{"signal_path":[{"is_muted":false,"is_passthrough":false,"quality":"high","gain":-50.0,"type":"digital_volume"},{"type":"output","method":"alsa","alsa_device":{"name":"NuForce µDAC 2","mixername":"USB Mixer","usbid":"1852:db96","id":"N2","driver":"USB-Audio","longname":"NuForce, Inc. NuForce µDAC 2 at usb-0000:00:14.0-3, full speed","components":"N2"},"quality":"lossless"}]},"status":"OutputMessage"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2675] {"message":{"signal_path":[{"is_muted":false,"is_passthrough":false,"quality":"high","gain":-50.0,"type":"digital_volume"},{"type":"output","method":"alsa","alsa_device":{"name":"NuForce µDAC 2","mixername":"USB Mixer","usbid":"1852:db96","id":"N2","driver":"USB-Audio","longname":"NuForce, Inc. NuForce µDAC 2 at usb-0000:00:14.0-3, full speed","components":"N2"},"quality":"lossless"}]},"status":"OutputMessage"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [86] {"message":{"signal_path":[{"quality":"lossless","type":"output","method":"alsa","alsa_device":{"components":"PCH","driver":"HDA-Intel","name":"HDA Intel PCH","longname":"HDA Intel PCH at 0x6001120000 irq 143","mixername":"Realtek ALC897","id":"PCH"}}]},"status":"OutputMessage"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] GOT [2685] {"message":{"signal_path":[{"alsa_device":{"name":"irDAC II","driver":"USB-Audio","usbid":"25c4:0008","longname":"ARCAM irDAC II at usb-0000:00:14.0-3, high speed","mixername":"USB Mixer","components":"II","id":"II"},"type":"output","quality":"lossless","method":"alsa"}]},"status":"OutputMessage"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2675] {"audio_port_tcp":34393,"status":"Success","clock_port":38182,"audio_port":0}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Idle => Prepared
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [86] {"clock_port":60748,"status":"Success","audio_port":0,"audio_port_tcp":45973}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Idle => Prepared
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] GOT [2685] {"audio_port_tcp":46417,"clock_port":57026,"audio_port":0,"status":"Success"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Idle => Prepared
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] synced to endpoint HDA Intel PCH DENON-AVR clock: realtime=87754133167265 rtt=103us offset=82296597201us delta=82296597201us
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] synced to endpoint NuForce µDAC 2 USB Audio clock: realtime=40923406112286 rtt=371us offset=35465870154us delta=35465870154us
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] synced to endpoint irDAC II clock: realtime=82945069596616 rtt=347us offset=77487533424us delta=77487533424us
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [87]{"request":"stream","stream_id":697069918,"first_seq":-1,"nak_port":-1,"buffer_size":10,"ready_threshold":0.2}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2676]{"request":"stream","stream_id":697069918,"first_seq":-1,"nak_port":-1,"buffer_size":10,"ready_threshold":0.2}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] SENT [2686]{"request":"stream","stream_id":697069918,"first_seq":-1,"nak_port":-1,"buffer_size":10,"ready_threshold":0.2}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [87] {"status":"Buffering"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Prepared => Buffering
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2676] {"status":"Buffering"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Prepared => Buffering
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [irDAC II] [raatclient] GOT [2686] {"status":"Buffering"}
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Prepared => Buffering
04/30 18:46:18 [Local 04/30 13:46:18] Trace: [Den + Study + Living Room] [zoneplayer/raat] [zoneplayer/raat] selected HDA Intel PCH DENON-AVR as clock master
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [prebuffer] ready 326400/960000 (34%) @ 0/628 sec
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [raat/tcpaudiosource] connecting to 127.0.0.1:45973
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [raat/tcpaudiosource] connected
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [87] {"status":"Ready"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Buffering => Ready
04/30 18:46:19 [Local 04/30 13:46:19] Info:
04/30 18:46:19 [Local 04/30 13:46:19] Info:
04/30 18:46:19 [Local 04/30 13:46:19] Info:
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [easyhttp] [2960] POST to https://api.roonlabs.net/swim/1/session/c9c2353145464eaab2caaf259f1e7b3b/continue?tidal=max returned after 1248 ms, status code: 200, request body size: 14 B
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] Skipping recently played track LibraryTrack[16029234, Stevie Wonder - The Definitive Collection [Universal] - My Cherie Amour IsAvailable=True IsDeleted=False ] last played 2.963141296216435 days ago
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] Skipping recently played track LibraryTrack[14728498, The Beatles - Abbey Road - Here Comes the Sun (2019 mix) IsAvailable=True IsDeleted=False ] last played 3.111440761648148 days ago
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] Skipping recently played track LibraryTrack[35533874, Rod Stewart - Ultimate Hits - Sometimes When We Touch IsAvailable=True IsDeleted=False ] last played 2.8614882207662036 days ago
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] Skipping recently played track LibraryTrack[24788530, The Beatles - The Beatles [White Album] - While My Guitar Gently Weeps IsAvailable=True IsDeleted=False ] last played 2.909724966224537 days ago
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [easyhttp] [2979] POST to https://api.roonlabs.net/metadata/1/tracks/translate?c=tidal-us&tidal=max returned after 129 ms, status code: 200, request body size: 486 B
04/30 18:46:19 [Local 04/30 13:46:19] Warn: [mlradio] [1] Merging tidal-us tracks: Result[Status=Success]
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:1162175 from Tidal, Local
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:5066421 from Local
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:4220 from Local
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:830051 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:1038885 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:159753 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:5237313 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:205614 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:276536 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:120956 from Local, Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:2980920 from Local
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:10150381 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:2156910 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:26644277 from Local, Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:5482 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:570370206 from Local
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:2651482 from Tidal, Local
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:545997302 from Local, Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:160079 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:554334236 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:205715 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:22227970 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:121132 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:2633756 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] accepting 192:0:2676767 from Tidal
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [raat/tcpaudiosource] connecting to 10.0.66.126:46417
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [raat/tcpaudiosource] connected
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [irDAC II] [raatclient] GOT [2686] {"status":"Ready"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Buffering => Ready
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [raat/tcpaudiosource] connecting to 10.0.47.102:34393
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [raat/tcpaudiosource] connected
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2676] {"status":"Ready"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Buffering => Ready
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] wait for ready in 0ms
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Adjusting playback start offset from 50ms to 75ms
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Starting at streamsample 0 and time 87755029817399 min_offset=75ms offset=75ms
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [88]{"request":"start","time":87755069377265,"stream_sample":0}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Ready => Playing
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2677]{"request":"start","time":40924342096786,"stream_sample":0}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Ready => Playing
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [irDAC II] [raatclient] SENT [2687]{"request":"start","time":82946005450316,"stream_sample":0}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Ready => Playing
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [87] {"status":"Playing"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [88] {"time":87755069377265,"status":"Success"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2676] {"status":"Playing"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [irDAC II] [raatclient] GOT [2686] {"status":"Playing"}
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [irDAC II] [raatclient] GOT [2687] {"time":82946005450316,"status":"Success"}
04/30 18:46:19 [Local 04/30 13:46:19] Debug: [easyhttp] [2980] POST to https://api.roonlabs.net/swim/1/session/c9c2353145464eaab2caaf259f1e7b3b/return?tidal=max returned after 205 ms, status code: 200, request body size: 513 B
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [mlradio] [1] [music/mlradio] returning 1 items for request of 1 items
04/30 18:46:19 [Local 04/30 13:46:19] Info: ComputeSwimType(LimitToSeed=False, PerformerIds.Count=0, ComposerIds.Count=0)
04/30 18:46:19 [Local 04/30 13:46:19] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2677] {"time":40924342096786,"status":"Success"}
04/30 18:46:20 [Local 04/30 13:46:20] Info: [stats] 37122mb Virtual, 3656mb Physical, 1909mb Managed, 1747mb estimated Unmanaged, 578 Handles, 82 Threads, 1.55% of runtime in GC pauses, 12ms last GC pause duration
04/30 18:46:20 [Local 04/30 13:46:20] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync irDAC II -> HDA Intel PCH DENON-AVR result: Success
04/30 18:46:20 [Local 04/30 13:46:20] Trace: [Den + Study + Living Room] [zoneplayer/raat] sync NuForce µDAC 2 USB Audio -> HDA Intel PCH DENON-AVR result: Success

Cory_Kim · April 30, 2026, 8:16pm

04/30 18:46:22 [Local 04/30 13:46:22] Trace: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] [zone] no playback for 5s, suspending to release audio device
04/30 18:46:22 [Local 04/30 13:46:22] Info:
04/30 18:46:22 [Local 04/30 13:46:22] Info:
04/30 18:46:22 [Local 04/30 13:46:22] Info:
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] Suspend
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] Stop
04/30 18:46:22 [Local 04/30 13:46:22] Info: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] OnPlayFeedback Stopped
04/30 18:46:22 [Local 04/30 13:46:22] Info: [zone Den + irDAC II + NuForce µDAC 2 USB Audio] Canceling Pending Sleep
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [Den] [Lossless, 24/96 TIDAL FLAC => 24/96] [100% buf] [PAUSED @ 0:03/10:28] Do I Do - Stevie Wonder
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [Study] [Lossless, 24/96 TIDAL FLAC => 24/96] [100% buf] [PAUSED @ 0:03/10:28] Do I Do - Stevie Wonder
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [Living Room] [HighQuality 77.7x, 24/96 TIDAL FLAC => 24/48] [100% buf] [PAUSED @ 0:03/10:28] Do I Do - Stevie Wonder
04/30 18:46:22 [Local 04/30 13:46:22] Debug: FTMSI-B closed file for ti/299D4435; open files:0
04/30 18:46:22 [Local 04/30 13:46:22] Info: [audio/env] [zoneplayer -> stream] All streams were disposed
04/30 18:46:22 [Local 04/30 13:46:22] Debug: FTMSI-B ti/299D4435 download status: FirstBlockRetrieved accessTimeout:False openFiles:0 prev:(FirstBlockRetrieved,False,1)
04/30 18:46:22 [Local 04/30 13:46:22] Info: FTMSI-B ti/299D4435: allocated bw changed from 51200 to 0 kbps
04/30 18:46:22 [Local 04/30 13:46:22] Info: FTMSI-B 1 FileCache ti/C0253D89 dwStatus:AllBlocksDownloaded files:0 accessTimeOut:True priorities: ('zoneplayer:8':38) --> bw limit:0kbps
04/30 18:46:22 [Local 04/30 13:46:22] Info: FTMSI-B 2 FileCache ti/299D4435 dwStatus:FirstBlockRetrieved files:0 accessTimeOut:False priorities: ('zoneplayer:8':39) --> bw limit:0kbps
04/30 18:46:22 [Local 04/30 13:46:22] Info: [audio/env] [zoneplayer] All streams were disposed
04/30 18:46:22 [Local 04/30 13:46:22] Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/30 18:46:22 [Local 04/30 13:46:22] Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/30 18:46:22 [Local 04/30 13:46:22] Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Playing => Prepared
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [89]{"request":"end_stream"}
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [87] {"status":"Ended"}
04/30 18:46:22 [Local 04/30 13:46:22] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [89] {"status":"Success"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [HDA Intel PCH DENON-AVR] [raatclient] SENT [90]{"request":"teardown"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint HDA Intel PCH DENON-AVR State Changed: Prepared => Idle
04/30 18:46:23 [Local 04/30 13:46:23] Debug: [raat/tcpaudiosource] disconnecting
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Playing => Prepared
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [irDAC II] [raatclient] SENT [2689]{"request":"end_stream"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [irDAC II] [raatclient] GOT [2686] {"status":"Ended"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [irDAC II] [raatclient] GOT [2689] {"status":"Success"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [irDAC II] [raatclient] SENT [2690]{"request":"teardown"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint irDAC II State Changed: Prepared => Idle
04/30 18:46:23 [Local 04/30 13:46:23] Debug: [raat/tcpaudiosource] disconnecting
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Playing => Prepared
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2679]{"request":"end_stream"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [HDA Intel PCH DENON-AVR] [raatclient] GOT [86] {"status":"Teardown"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2676] {"status":"Ended"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2679] {"status":"Success"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [NuForce µDAC 2 USB Audio] [raatclient] SENT [2680]{"request":"teardown"}
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [Den + Study + Living Room] [zoneplayer/raat] Endpoint NuForce µDAC 2 USB Audio State Changed: Prepared => Idle
04/30 18:46:23 [Local 04/30 13:46:23] Debug: [raat/tcpaudiosource] disconnecting
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [irDAC II] [raatclient] GOT [2685] {"status":"Teardown"}
04/30 18:46:23 [Local 04/30 13:46:23] Info: sleep 55ms after flush
04/30 18:46:23 [Local 04/30 13:46:23] Trace: [NuForce µDAC 2 USB Audio] [raatclient] GOT [2675] {"status":"Teardown"}
04/30 18:46:23 [Local 04/30 13:46:23] Debug: FTMSI-B ti/299D4435 download status: FirstBlockRetrieved accessTimeout:True openFiles:0 prev:(FirstBlockRetrieved,False,0)
04/30 18:46:35 [Local 04/30 13:46:35] Info: [stats] 37057mb Virtual, 3656mb Physical, 1912mb Managed, 1744mb estimated Unmanaged, 574 Handles, 71 Threads, 1.55% of runtime in GC pauses, 10ms last GC pause duration
04/30 18:46:45 [Local 04/30 13:46:45] Trace: [library] endmutation in 11ms
04/30 18:46:50 [Local 04/30 13:46:50] Info: [stats] 37033mb Virtual, 3656mb Physical, 1918mb Managed, 1738mb estimated Unmanaged, 574 Handles, 71 Threads, 1.55% of runtime in GC pauses, 11ms last GC pause duration

Cory_Kim · April 30, 2026, 10:37pm

My earlier example involved Tidal tracks. I’ve reproduced the error with local tracks as well. Here is some analysis from Claude:

—-

I’ve identified three problems from the server logs:

PROBLEM 1: Prebuffer fails to load the next track before the current track ends

This is the root cause. While playing in grouped zones, the server’s prebuffer mechanism fails to read the next track in time. This happens with both local files and TIDAL streams.

Here is a representative example with a local DSD file (no network/streaming involved):

16:52:20 [Den] [DSD64 DSF => 32/176] [100% buf] [PLAYING @ 3:03/3:23] Any Way You Want It - Journey
16:52:25 [prebuffer] short read: 0 / 564480 fill=3471008
16:52:30 [Den] [DSD64 DSF => 32/176] [56% buf] [PLAYING @ 3:13/3:23]
16:52:35 [Den] [DSD64 DSF => 32/176] [2% buf] [PLAYING @ 3:18/3:23]
16:52:41 [HDA Intel PCH DENON-AVR] [raatclient] GOT {“status”:“Dropout”,“samples”:6021}
16:52:44 Warn: [Den + Study + Living Room] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream

The prebuffer returned zero bytes (“short read: 0 / 564480”) while the track still had 58 seconds of playback remaining. The buffer then drained from 100% to 2% in 10 seconds as the server consumed audio without replenishing it.

The same pattern occurs with TIDAL hi-res content:

18:46:04 [Den] [24/176 TIDAL FLAC => 24/176] [49% buf] [PLAYING @ 2:31/2:41] Walk On - Neil Young
18:46:09 [Den] [24/176 TIDAL FLAC => 24/176] [3% buf] [PLAYING @ 2:36/2:41]
18:46:14 [irDAC II] [raatclient] GOT {“samples”:58100,“status”:“Dropout”}
18:46:17 Warn: [Den + Study + Living Room] [zoneplayer/raat] Too many dropouts (>3s dropped out in the last 30s). Killing stream

In both cases, the server’s own local output (HDA Intel PCH) starves alongside the remote endpoints, ruling out network as a factor.

PROBLEM 2: Dropout recovery causes a double track advance, skipping a track

When the dropout threshold kills the stream, the zone layer misinterprets it as a natural end-of-media event. This triggers a track advance, but the zone player’s internal state becomes confused:

16:52:44 Info: [zone HDA Intel PCH DENON-AVR + Study + NuForce µDAC 2 USB Audio] OnPlayFeedback StoppedEndOfMediaNatural
16:52:44 Debug: [zone HDA Intel PCH DENON-AVR + Study + NuForce µDAC 2 USB Audio] _Advance (Track)
16:52:44 Trace: [Den] [LOADING @ 0:00] Hot for Teacher - Van Halen
16:52:44 Info: [Den + Study + Living Room] [zoneplayer] BufferingTrack == NextTrack during ClearQueuedMedia, setting _stop_on_next_track_transition
16:52:44 Info: [Den + Study + Living Room] [zoneplayer] Aborting play because track changed
16:52:44 Info: [zone HDA Intel PCH DENON-AVR + Study + NuForce µDAC 2 USB Audio] OnPlayFeedback StoppedEndOfMediaNatural
16:52:44 Debug: [zone HDA Intel PCH DENON-AVR + Study + NuForce µDAC 2 USB Audio] _Advance (Track)
16:52:44 Trace: [Den] [STOPPED @ 0:00] Rock of Ages - Def Leppard

The zone player advanced from Journey to Van Halen (“Hot for Teacher”), then immediately aborted and advanced again to Def Leppard (“Rock of Ages”). “Hot for Teacher” was skipped entirely and never played.

PROBLEM 3: Server kills its own successfully recovered playback

After the double advance, the RAAT transport layer successfully recovers. It tears down, re-sets up all endpoints at the new format (16/44 FLAC), syncs clocks, and all three endpoints reach Playing state. Playback genuinely resumes.

However, the _stop_on_next_track_transition flag set during the confused recovery causes the higher-level zone controller to kill the stream:

16:52:44 [Den] [16/44 FLAC => 16/44] [2% buf] [PLAYING @ 0:00] Rock of Ages - Def Leppard
16:52:44 All endpoints reach Playing state, syncs succeed
16:52:49 [zone] no playback for 5s, suspending to release audio device
16:52:49 [Den] [16/44 FLAC => 16/44] [100% buf] [PAUSED @ 0:04/4:08] Rock of Ages - Def Leppard

The server pauses playback at 0:04 into the track with a full 100% buffer, despite all endpoints working correctly. The transport recovered; the zone layer killed it.

Summary:

The prebuffer fails to load the next track before the current one ends in grouped zones, causing the buffer to drain to near-zero
When the resulting dropouts kill the stream, the zone layer misinterprets it as a natural track end and double-advances, skipping a track
The _stop_on_next_track_transition flag set during this confused state causes the server to kill its own successfully recovered playback

This is not related to Docker, network, TIDAL, or endpoint hardware. It reproduces with local files on the server’s own audio output. The previously reported threading bug (InvalidOperationException in SharedObject.Read() within ev_too_many_dropouts) appears to be fixed in this build — thank you.

I’m happy to provide complete logs, reproduce on demand, or test any patches.