Seldom dropouts on beginning of next track on PS Audio DS with Bridge2

Hello, lately (probably somewhere around Roon release when RAAT was switched from UDP to TCP?) i am occasionally getting 1-3 second dropouts on beginning of the track (be it local or tidal).

HW and NW should be fine i believe (Roon running on i7 NUC with Linux and dedicated NW interface for the Bridge2 - connected via TP-Link optical transceivers).

I did not have this issue before (there was Roon release and new Bridge2 firmware release around the same time when it started to appear - so i guess the guilty would be one of those two…).

Here is the log + interface stats taken after I got another short dropout today:

08/19 11:02:24 Trace: [zoneplayer/raat] Endpoint PS Audio DirectStream DAC State Changed: Playing => Prepared
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] SENT [9445]{"request":"end_stream"}
08/19 11:02:24 Debug: Lastfm 'ac86c2e5504f0240c7c0b565650cf441' DONE: Wham! - Heartbeat 
08/19 11:02:24 Info: [library] recorded play for profile 6b1d9a0c-e7d0-421c-8c07-18e015e342c6: mediaid=50:1:8a4668ff-092d-4c1f-bc8f-62bc886088a4 metadataid=123:0:MT00091858
08/19 11:02:24 Trace: [library] finished with 8 dirty tracks 1 dirty albums 8 dirty performers 8 dirty works 8 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 c
08/19 11:02:24 Debug: [library/index] updating search indices: 8 ops 0 adds, 0 removes
08/19 11:02:24 Trace: [library] endmutation in 25ms
08/19 11:02:24 Info: [zoneplayer/base] Playing: /music/__TORQ-FLAC-VA/Greatest 1980s music hit singles/Wham! -  I'm Your Man.flac
08/19 11:02:24 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
08/19 11:02:24 Debug: [raat/tcpaudiosource] disconnecting
08/19 11:02:24 Info: [audio/env] [zoneplayer -> stream -> endpoint] All streams were disposed
08/19 11:02:24 Info: [audio/env] [zoneplayer] All streams were disposed
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] SENT [9447]{"request":"update_artwork","mimetype":"image/jpeg"}
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9160] {"status":"Ended"}
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9445] {"status":"Success"}
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9447] {"status":"Success"}
08/19 11:02:24 Info: sleep 160ms after flush
08/19 11:02:24 Info: [zoneplayer/base] Queueing: /music/Wham!/1984 Make It Big (2001 Remastered Japan Edition SACD) [16@44]/05 Freedom.flac
08/19 11:02:24 Info: [zoneplayer/base]     Open Result (Playing):Result[Status=Success]
08/19 11:02:24 Info: [zoneplayer/base] Starting playback
08/19 11:02:24 Trace: [zoneplayer/raat] StartStream Sooloos.Broker.Transport.RaatZonePlayer+Endpoint: StreamFormat(channels=2, bitspersample=16, samplerate=44100, isdts=Fal
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] SENT [9450]{"request":"teardown"}
08/19 11:02:24 Trace: [zoneplayer/raat] Endpoint PS Audio DirectStream DAC State Changed: Prepared => Idle
08/19 11:02:24 Info: SETUP FORMAT StreamFormat(channels=2, bitspersample=16, samplerate=44100, isdts=False)
08/19 11:02:24 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] SENT [9451]{"request":"setup","format":{"sample_type":"pcm","sample_rate":441
08/19 11:02:24 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Flac 44100/16/2 BitRate=995 Quality=Lossless
    Raat Device=PS Audio DirectStream DAC
    Output OutputType=Local_Analog Quality=Lossless
------------------------------------------------------------
08/19 11:02:24 Debug: Lastfm 'ac86c2e5504f0240c7c0b565650cf441' START: Wham! - I'm Your Man  [1986 short version  3_01] 
08/19 11:02:24 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/246 sec
08/19 11:02:24 Info: [zoneplayer/base] Open result (Queueing): Result[Status=Success]
08/19 11:02:24 Trace: [prebuffer] ready 299880/882000 (34%) @ 0/301 sec
08/19 11:02:25 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9157] {"status":"Teardown"}
08/19 11:02:25 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9451] {"message":{"signal_path":[{"method":"analog","type":"output","qua
08/19 11:02:25 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9451] {"audio_port":0,"status":"Success","audio_port_tcp":47335,"clock_p
08/19 11:02:25 Trace: [zoneplayer/raat] Endpoint PS Audio DirectStream DAC State Changed: Idle => Prepared
08/19 11:02:25 Trace: [zoneplayer/raat] synced to endpoint clock. realtime=48524176947168 rtt=673us offset=26802775084us delta=26802775084us
08/19 11:02:25 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] SENT [9453]{"request":"stream","stream_id":953748709,"first_seq":-1,"nak_port
08/19 11:02:25 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"status":"Buffering"}
08/19 11:02:25 Trace: [zoneplayer/raat] Endpoint PS Audio DirectStream DAC State Changed: Prepared => Buffering
08/19 11:02:25 Trace: [zoneplayer/raat] [zoneplayer/raat] selected PS Audio DirectStream DAC as clock master
08/19 11:02:25 Trace: [prebuffer] status 441000/441000 (100%) @ 0/246 sec
08/19 11:02:25 Debug: [raat/tcpaudiosource] connecting to 192.168.52.52:47335
08/19 11:02:25 Debug: [raat/tcpaudiosource] connected
08/19 11:02:25 Warn: [raat/tcpaudiosource] send failed: unexpected partial write
08/19 11:02:25 Warn: [raat/tcpaudiosource] disconnecting + retrying
08/19 11:02:25 Debug: [raat/tcpaudiosource] disconnecting
08/19 11:02:32 Info: [stats] 6243mb Virtual, 2297mb Physical, 679mb Managed, 0 Handles, 71 Threads
08/19 11:02:35 Warn: [zoneplayer/raat] Endpoint failed to become ready in 10s. Proceeding in state Buffering
08/19 11:02:35 Trace: [zoneplayer/raat] Endpoint PS Audio DirectStream DAC State Changed: Buffering => Ready
08/19 11:02:35 Trace: [zoneplayer/raat] wait for ready in 10000ms
08/19 11:02:35 Trace: [zoneplayer/raat] Adjusting playback start offset from 50ms to 180ms
08/19 11:02:35 Trace: [zoneplayer/raat] Starting at streamsample 0 and time 48534276936168 min_offset=180ms offset=180ms
08/19 11:02:35 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] SENT [9454]{"request":"start","time":48534437044168,"stream_sample":0}
08/19 11:02:35 Trace: [zoneplayer/raat] Endpoint PS Audio DirectStream DAC State Changed: Ready => Playing
08/19 11:02:35 Trace: [prebuffer] status 441000/441000 (100%) @ 2/246 sec
08/19 11:02:35 Debug: [raat/tcpaudiosource] connecting to 192.168.52.52:47335
08/19 11:02:35 Debug: [raat/tcpaudiosource] connected
08/19 11:02:35 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"status":"Playing"}
08/19 11:02:35 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9454] {"status":"Success"}
08/19 11:02:35 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"samples":10870,"status":"Dropout"}
08/19 11:02:36 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"samples":21168,"status":"Dropout"}
08/19 11:02:36 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"samples":21168,"status":"Dropout"}
08/19 11:02:37 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"samples":21168,"status":"Dropout"}
08/19 11:02:37 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"samples":21168,"status":"Dropout"}
08/19 11:02:38 Trace: [transport/raatclient] [PS Audio DirectStream DAC @ 192.168.52.52:49993] GOT [9453] {"samples":9458,"status":"Dropout"}
08/19 11:02:40 Trace: [prebuffer] status 441000/441000 (100%) @ 8/246 sec
08/19 11:02:45 Trace: [prebuffer] status 441000/441000 (100%) @ 13/246 sec
08/19 11:02:47 Info: [stats] 6243mb Virtual, 2298mb Physical, 679mb Managed, 0 Handles, 63 Threads
08/19 11:02:50 Trace: [prebuffer] status 441000/441000 (100%) @ 18/246 sec
08/19 11:02:55 Trace: [zoneplayer/raat] sync PS Audio DirectStream DAC: realtime=48554435207569 rtt=606us offset=26802775054us delta=113us drift=-29us in 30.258436s (-0.978
08/19 11:02:55 Trace: [prebuffer] status 441000/441000 (100%) @ 23/246 sec
08/19 11:03:00 Trace: [prebuffer] status 441000/441000 (100%) @ 28/246 sec
08/19 11:03:02 Info: [stats] 6243mb Virtual, 2298mb Physical, 679mb Managed, 0 Handles, 63 Threads
08/19 11:03:06 Trace: [prebuffer] status 441000/441000 (100%) @ 33/246 sec
08/19 11:03:11 Trace: [prebuffer] status 441000/441000 (100%) @ 38/246 sec
08/19 11:03:16 Trace: [prebuffer] status 441000/441000 (100%) @ 43/246 sec
08/19 11:03:17 Info: [stats] 6243mb Virtual, 2298mb Physical, 680mb Managed, 0 Handles, 63 Threads
08/19 11:03:21 Trace: [prebuffer] status 441000/441000 (100%) @ 48/246 sec
08/19 11:03:25 Trace: [zoneplayer/raat] sync PS Audio DirectStream DAC: realtime=48584643344836 rtt=1629us offset=26802771995us delta=-3199us drift=-3088us in 60.469701s (-
08/19 11:03:26 Trace: [prebuffer] status 441000/441000 (100%) @ 53/246 sec
08/19 11:03:31 Trace: [prebuffer] status 441000/441000 (100%) @ 59/246 sec

mii-tool eth3

eth3: negotiated 100baseTx-FD, link ok

ifconfig eth3

eth3      Link encap:Ethernet  HWaddr e8:80:2e:e7:39:05  
          inet addr:192.168.52.1  Bcast:192.168.52.255  Mask:255.255.255.0
          inet6 addr: fe80::ea80:2eff:fee7:3905/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:16166142 errors:0 dropped:0 overruns:0 frame:0
          TX packets:43678372 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:1159546512 (1.1 GB)  TX bytes:59236307286 (59.2 GB)

Many thanks!

Hi @maniac ---- Thank you for the post and sharing your feedback with us! Both are very appreciated!

Moving forward, may I very kindly ask you to please verify how your musical collection is being accessed/stored. Also, if you could please describe your network configuration/topology, as well as providing insight into any networking hardware you are currently implementing.

-Eric

Hi Eric, here is my setup in more detail (in case you’d need more just let me know):

RoonServer 1.3.247 running on i7 Skylake NUC 6I7KYK under Ubuntu 16.04.3 64bit with renice -19 (max priority). In the same NUC I am running another 2 linux VMs with negligible load (usually about 5-10% cpu load, while CPU maintains 0,9~1,2 GHz frequency range most of the time). There is 64bit linux kernel 4.9.34 in place. There is one SSD disk inside (Samsung 950PRO NVME).

To connect to PSA Bridge2 i have dedicated Apple USB 2.0 (ASIX based) ethernet adapter with media auto-negotiation enabled and correctly negotiated too 100Mbps FDX (Bridge2 and also MC110CS supports only 100mbps max). This ASIX adapter have all offloading set to off (default) except generic-receive-offload (checked via ethtool -k).

The ASIX ethernet interface is then connected via CAT6 shielded cable towards pair of MC110CS optical transceivers providing galvanic isolation, which are then further connected to PSA Bridge2.

ASIX shares same USB bus with integrated wireless adapter inside the NUC, however this wlan is not configured and turned off, here is the detail of lsusb -t: (please note there are another two USB3 Lenovo NICs on other usb bus not listed here)
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/16p, 480M
|__ Port 1: Dev 2, If 0, Class=Vendor Specific Class, Driver=asix, 480M
|__ Port 4: Dev 3, If 0, Class=Vendor Specific Class, Driver=ftdi_sio, 12M
|__ Port 9: Dev 4, If 0, Class=Wireless, Driver=btusb, 12M
|__ Port 9: Dev 4, If 1, Class=Wireless, Driver=btusb, 12M

So there is no switch, nor another device in the path except the transceivers.

There are some iptables firewalling rules, however not related to this interface so this connection is fully free to communicate in both directions.

ASIX adapter reports no issues after 47days of uptime (several music dropouts happened from that time already):
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:22547468 errors:0 dropped:0 overruns:0 frame:0
TX packets:62253013 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000

Now more to the music storage details:
LAN: I Have two different folders mounted on the Ubuntu via NFSv4 from QNAP TS869PRO with latest QTS4.3.3 (dualcore Atom 2,13GHz) with following parameters: rw,noatime,vers=4.0,rsize=32768,wsize=32768,namlen=255,hard,proto=tcp,port=0,timeo=600,retrans=2,sec=sys,local_lock=none
which gives me 100MB/s throughput most of the time. It’s connected via HP unmanaged L2 switch. There are few dropped packets there (474 dropouts after 6TB transferred data) which i believe should not pose any issue though.

WAN: I am using also TIDAL, where traffic from Ubuntu is (quite strangely, i have to admit :wink: ) routed via one of the VMs on the same NUC which acts as router/firewall etc which is connected via 250Mbit/250Mbit line to internet.

I have just tried to max out the NUC and QNAP (cpu+disks+nw ifaces - up to the point of thermal throttling of the NUC) and it had no apparent impact on the dropout occurrence when skipping to next track.

As the dropouts happen also with TIDAL i believe the culprit is between RoonServer and client (specifically the PSA Bridge2) . When trying to play via Roon on my notebook i have got no dropouts.

As i’m not sure how to attach files here, here is the link to three excerpts from RoonServer_log.txt: one where hitting Next button resulted in success without dropouts, second is when the dropout occurred and third is egrep from log showing bit more history (Warn messages plus format and tidal identification): http://www.localhost.sk/dropzone/roondebug-maniac-0Dho8sFJPm.zip

In case you’d like me to send you tcpdump pcpap dump of RoonServer-PSA_bridge communication please let me know :slight_smile:

Hi @maniac ----- Thank you for the very extensive follow up, your diligence is very appreciated :sunglasses:

Moving forward, based on your feedback, the first bit of information that jumped out at me was where your musical collection is being stored: QNAP TS869PRO with latest QTS4.3.3 (dualcore Atom 2,13GHz). I think it is important to point out that when we hear of audio dropouts, they are usually linked to some sort of performance, hardware, or configuration issue.

As a point of reference, this is a comparison of the processor we recommend as a minimum, versus the processor in that particular QNAP:

By chance, have you tried testing with some locally stored content on the device hosting your core? I am curious as to how things behave with the NAS, temporarily being bypassed.

-Eric

Ji Eric, please note that i am easily getting 100MB/s (1Gbps) from the Qnap via NFS. there are two raid5 arrays each over 10TB capacity (music stored there is only about 2TB / cca 6k albums).

Also the fact is that the dropouts are being happening also with Tidal - ruling out the Qnap. Also this oldie Qnap don’t sweat a bit while streaming 16GB movie or DSD128 / FLAC24@192. Dropouts happen (seldom) ONLY when i skip to next track.

Just for the sake of consistency i will try to upload few albums on the NVME SSD in NUC and will let you know.

In case you was looking into the logfiles i’ve shared please focus on today’s logs where i know the qnap was idling most of the time.

Ok, music is now in copied from Qnap to NVE, now just to have to find best way how to tag it in the Roon to be sure it’s playing from the NVME. Should not take long i guess :slight_smile:

(rsync) sent 5,602,523,544 bytes received 1,353 bytes 104,720,091.53 bytes/sec

Hi Eric,

as suggested I have now tested playing directly from SSD towards the bridge. The Dropouts still seldomly occur when hitting the Next (Skip) button in the roon. This happens also with 16@44 flac files.

I did further analysis proving that this is not the source (Qnap) issue (located here: http://www.localhost.sk/dropzone/Dropout-vs-ioping-via-nfs-to-qnap-xwNLi4ZeTe.zip) , and now i have suspicion it is the PSA Bridge2 side issue based on the NW traffic analysis between Roon and Bridge2 -> it seems that Bridge2 cannot process further data based on the TCP WINDOW FULL TCP connection status as seen in Wireshark (located here: http://www.localhost.sk/dropzone/Dropout-vs-wireshark-pYtcIaYRQ4.zip) .

Please let me know if i can test something further (i have not rebooted the PSA Bridge2 for some time for e.g. …).

Thank you!

Hi @maniac ----- Thank you for the follow up and sharing your observations after performing the proposed test.

Moving forward, I had a chance to discuss this behavior with the team today, along with one of our developers and we are going to be conducting some internal testing to see if we can replicate this same behavior. Once testing has completed and I have some more feedback I will be sure to update you accordingly. Your patience, is very appreciated!

-Eric

1 Like

Hi Eric, in the meantime i had left Roon playing onto background to find out if this happens only when I manually skip, or also during normal transition to the next track. What i have found out is that this dropouts sometimes happens also during natural skip to next track without user interaction.
Here is some additional data: http://www.localhost.sk/dropzone/Dropout-netdata-network-details-m25amHj66W.zip

Short description - Roon (1.3 build 259, radio mode) was playing fine 24@88 file from Qnap storage, then when track finished and next track was supposed to start (from Tidal) - dropout happened.
nobody was at home by that time e.g. no user interaction with Roon / DS DAC brdige2 was done.

Attached files are from NUC where Roon server is running, probably nothing really new there, just one can easily see that Tidal track buffering was pretty fast (cca 80Mbps - eth0) , followed by an gap in communication between Roon and bridge2 while (eth3).

And just to put my wording of “seldom” into perspective - in the last 24 hours of continuous playing on background, the dropouts happened 3 times. Of course when frequently skipping manually to next track this would happen sooner.

Thx, maniac

I have another update - this actually never happen before. As i left Roon radio continuously playing for last few days (with preamp/amps turned off for whole yesterday) - today i just wanted to play something but after starting Roon on my book it can’t find PSA Bridge2 anymore…
I am able to ping it, able to play via UPnP, even able to connect to tcp port RoonServer is trying to contact (49993) - but there is no answer on the port (just stays open even if i try to send some ambiguous GET / HTTP/1,0 whatever). Seems that I my only chance now to get Roon playback back is to reboot the DAC? thx

Hi @maniac ---- Thank you for touching base and sharing this most recent observation. I am sorry to hear of the troubles.

Can you verify for me that everything is up to date with the DirectStream?

-Eric

not sure about the PIC, but the other seems to be newer in my system:

Hi @maniac ----- Thank you for the post, my apologies as I must’ve pulled the wrong screenshot above :innocent: I would agree that everything in your system is up to date.

I will be discussing this behavior in further detail today with the team to get some insight on this behavior, once I have some feedback I will be sure to touch base with you in a timely manor.

-Eric