Skipping or clipping audio with static noise regularly

Leon_Roy · May 21, 2021, 5:03pm

Core Machine

OS: VMware ESXi 6.5 > running Ubuntu Ubuntu 18.04.5 LTS VM > Roon inside Docker
Machine: [

NUC8i5BEH

](Intel® NUC Kit NUC8i5BEH)
RAM: 12GB assigned to VM
CPU: Quad core assigned to VM
Storage: SSD for ESXi
Music Storage: Music is hosted on an NFS mount on the Ubuntu Docker host and mounted inside Roon as a local store

Network Details

ESXi on wired Gigabit > HP Procurve switch > Synology NAS

Audio Devices

Sonos One speaker - wired ethernet to switch

Library Size

22k tracks

Description of Issue

Music often skips to the next track before the track has finished playing. Occassional audio glitches like a CD data track being played.

** Trace **

I’ve also marked exactly where the audio skips at 05/21 13:57:25

05/21 13:57:18 Info: [library] saved recent ProfileId=2a3e764c-5db1-45e1-b91a-eb3f2995c9f7 Time=05/21/2021 12:57:18 DataType=album Type=play MetadataId=7623289 ContentId=4874031 LibraryId=4874031
05/21 13:57:18 Trace: [zone Study] Playing 19 Items
05/21 13:57:18 Info: [zone Study] OnPlayFeedback Stopped
05/21 13:57:18 Info: [Study] [zoneplayer] BufferingTrack == NextTrack during ClearQueuedMedia, setting _stop_on_next_track_transition
05/21 13:57:18 Info: [zone Study] Canceling Pending Sleep
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Playing
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] State transition Playing => Disconnected
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:18 Trace: [zone Study] Playing TransportItem
05/21 13:57:18 Info: [audio/env] [zoneplayer] All streams were disposed
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:18 Info: [zone Study] Canceling Pending Sleep
05/21 13:57:18 Trace: [zone Study] Selecting Source state=Stopped
05/21 13:57:18 Trace: [Study] [HighQuality, 16/44 FLAC => 16/44] [22% buf] [LOADING @ 0:00] Dearest John - Cliff Martinez / Gregory Tripi
05/21 13:57:18 Info: [Study] [zoneplayer] Playing: /music/Cliff Martinez/Cliff Martinez - The Knick Season 2 (2015) [Original Release - Milan - M2-36751 - CD]/01 Dearest John.flac
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:18 Info: [Study] [zoneplayer] Queueing: /music/Cliff Martinez/Cliff Martinez - The Knick Season 2 (2015) [Original Release - Milan - M2-36751 - CD]/02 It's My Eye.flac
05/21 13:57:18 Info: [Study] [zoneplayer] Open result (Queueing): Result[Status=Success]
05/21 13:57:18 Info: [Study] [zoneplayer]     Open Result (Playing):Result[Status=Success]
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:18 Info: [Study] [zoneplayer] Starting playback
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] backend StartStream 1, bytesperframe: 4, channels: 2, samplerate: 44100, bits per sample: 16, seq: 20, thread
05/21 13:57:18 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/234 sec
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: False, tx path: /277f070c8a744c94b4a20643a30b4ba7/Roon5a83a5436ea245338a29fbf905d5b253.flac, stream path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, method: Get
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] State transition Disconnected => WaitForStatus
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: False, tx path: /e91c688c4b2648f6bfbae3c7412fdc7d/Roon6.flac, stream path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, method: Get
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] groupandplay start, seq: 20, _seq: 20
05/21 13:57:18 Trace: [client/sonos] seturiasync start, device: uuid:RINCON_7828CAFB334A01400, uri: http://10.1.0.44:9104/3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] StartStream end
05/21 13:57:18 Trace: [client/sonos] seturi request, uri: http://10.1.0.44:9104/3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac
05/21 13:57:18 Info: [zone Study] OnPlayFeedback Playing
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction completed
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: True, did stream end: False, tx path: /277f070c8a744c94b4a20643a30b4ba7/Roon5a83a5436ea245338a29fbf905d5b253.flac, stream path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, method: Get
05/21 13:57:18 Trace: [Study] [HighQuality, 16/44 FLAC => 16/44] [32% buf] [PLAYING @ 0:00] Dearest John - Cliff Martinez / Gregory Tripi
05/21 13:57:18 Trace: [client/sonos] seturi response, uri: http://10.1.0.44:9104/3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac
05/21 13:57:18 Trace: [client/sonos] play request
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] request matches stream, current path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, next path:
05/21 13:57:18 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/125 sec
05/21 13:57:18 Warn: applying gain to 0 samples??? offset=8820 count=297 nsamples=8820
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] request matches stream, current path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, next path:
05/21 13:57:18 Trace: [client/sonos] play response
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] groupandplay end
05/21 13:57:18 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: True, did stream end: False, tx path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, stream path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, method: Get
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction canceled, queue new stream
05/21 13:57:18 Trace: [client/sonos] next uri request
05/21 13:57:18 Trace: [client/sonos] next uri response
05/21 13:57:18 Trace: [client/sonos] av_status
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] state from device: TRANSITIONING
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos]  zoneplayer state: WaitForStatus
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] request matches stream, current path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, next path: /2f0ad812ec2941cebe2731e314b0468e/Roon6.flac
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] startpos is out of range, returning file headers only.  start, pos, sum, end, offset: 0, 7035365, 528429, 352800
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction completed
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: True, did stream end: False, tx path: /2f0ad812ec2941cebe2731e314b0468e/Roon6.flac, stream path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, method: Get
05/21 13:57:18 Trace: [client/sonos] av_status
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] state from device: PLAYING
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos]  zoneplayer state: WaitForStatus
05/21 13:57:18 Trace: [endpoint/sonos/uuid:RINCON_7828CAFB334A01400] check zone coordinator, device coordinator: RINCON_7828CAFB334A01400, roon coordinator: RINCON_7828CAFB334A01400
05/21 13:57:18 Trace: [Study] [zoneplayer/sonos] State transition WaitForStatus => Playing
05/21 13:57:18 Info:
--[ SignalPath ]---------------------------------------------
SignalPath Quality = HighQuality
Elements:
    Source Format=Flac 44100/16/2 BitRate=473 Quality=Lossless
    UpgradeBitDepth FromBitsPerSample=16 ToBitsPerSample=64 Quality=Lossless
    VolumeNormaliation GainDb=-2.97519547416396 Quality=Enhanced
    Truncate FromBitsPerSample=64 ToBitsPerSample=16 Quality=HighQuality
    Output OutputType=Sonos Quality=Lossless SubType= Model=ONE
------------------------------------------------------------
05/21 13:57:18 Info:
--[ SignalPath ]---------------------------------------------
SignalPath Quality = HighQuality
Elements:
    Source Format=Flac 44100/16/2 BitRate=473 Quality=Lossless
    UpgradeBitDepth FromBitsPerSample=16 ToBitsPerSample=64 Quality=Lossless
    VolumeNormaliation GainDb=-2.97519547416396 Quality=Enhanced
    Truncate FromBitsPerSample=64 ToBitsPerSample=16 Quality=HighQuality
    Output OutputType=Sonos Quality=Lossless SubType= Model=ONE
------------------------------------------------------------
05/21 13:57:20 Trace: [prebuffer] short read: 0 / 8820 fill=433647
05/21 13:57:22 Info: [library] saved recent ProfileId=2a3e764c-5db1-45e1-b91a-eb3f2995c9f7 Time=05/21/2021 12:57:22 DataType=album Type=play MetadataId=7623289 ContentId=4874031 LibraryId=4874031
05/21 13:57:22 Trace: [zone Study] Playing 19 Items
05/21 13:57:22 Info: [zone Study] OnPlayFeedback Stopped
05/21 13:57:22 Info: [zone Study] Canceling Pending Sleep
05/21 13:57:22 Info: [Study] [zoneplayer] BufferingTrack == NextTrack during ClearQueuedMedia, setting _stop_on_next_track_transition
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Playing
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] State transition Playing => Disconnected
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:22 Trace: [zone Study] Playing TransportItem
05/21 13:57:22 Info: [zone Study] Canceling Pending Sleep
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:22 Trace: [zone Study] Selecting Source state=Stopped
05/21 13:57:22 Info: [audio/env] [zoneplayer] All streams were disposed
05/21 13:57:22 Trace: [Study] [HighQuality, 16/44 FLAC => 16/44] [32% buf] [LOADING @ 0:00] Dearest John - Cliff Martinez / Gregory Tripi
05/21 13:57:22 Info: [Study] [zoneplayer] Playing: /music/Cliff Martinez/Cliff Martinez - The Knick Season 2 (2015) [Original Release - Milan - M2-36751 - CD]/01 Dearest John.flac
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:22 Info: [Study] [zoneplayer] Queueing: /music/Cliff Martinez/Cliff Martinez - The Knick Season 2 (2015) [Original Release - Milan - M2-36751 - CD]/02 It's My Eye.flac
05/21 13:57:22 Info: [Study] [zoneplayer]     Open Result (Playing):Result[Status=Success]
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] endstream, zp state: Disconnected
05/21 13:57:22 Info: [Study] [zoneplayer] Starting playback
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] backend StartStream 1, bytesperframe: 4, channels: 2, samplerate: 44100, bits per sample: 16, seq: 21, thread
05/21 13:57:22 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/234 sec
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: False, tx path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, stream path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, method: Get
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: False, tx path: /277f070c8a744c94b4a20643a30b4ba7/Roon5a83a5436ea245338a29fbf905d5b253.flac, stream path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, method: Get
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] State transition Disconnected => WaitForStatus
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: False, did stream end: False, tx path: /2f0ad812ec2941cebe2731e314b0468e/Roon6.flac, stream path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, method: Get
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] groupandplay start, seq: 21, _seq: 21
05/21 13:57:22 Trace: [client/sonos] seturiasync start, device: uuid:RINCON_7828CAFB334A01400, uri: http://10.1.0.44:9104/c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac
05/21 13:57:22 Trace: [client/sonos] seturi request, uri: http://10.1.0.44:9104/c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] StartStream end
05/21 13:57:22 Info: [Study] [zoneplayer] Open result (Queueing): Result[Status=Success]
05/21 13:57:22 Info: [zone Study] OnPlayFeedback Playing
05/21 13:57:22 Trace: [Study] [HighQuality, 16/44 FLAC => 16/44] [24% buf] [PLAYING @ 0:00] Dearest John - Cliff Martinez / Gregory Tripi
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction completed
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: True, did stream end: False, tx path: /3b9ca6edb22f4582b7c0e54a8504fd4c/Roone11cc5274acb464fbb184a9fe5fe4986.flac, stream path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, method: Get
05/21 13:57:22 Trace: [client/sonos] seturi response, uri: http://10.1.0.44:9104/c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac
05/21 13:57:22 Trace: [client/sonos] play request
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] request matches stream, current path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, next path:
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] request matches stream, current path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, next path:
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: True, did stream end: False, tx path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, stream path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, method: Get
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, queue new stream
05/21 13:57:22 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/125 sec
05/21 13:57:22 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
05/21 13:57:22 Trace: [client/sonos] av_status
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] state from device: TRANSITIONING
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos]  zoneplayer state: WaitForStatus
05/21 13:57:22 Trace: [client/sonos] av_status
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] state from device: PLAYING
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos]  zoneplayer state: WaitForStatus
05/21 13:57:22 Trace: [endpoint/sonos/uuid:RINCON_7828CAFB334A01400] check zone coordinator, device coordinator: RINCON_7828CAFB334A01400, roon coordinator: RINCON_7828CAFB334A01400
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] State transition WaitForStatus => Playing
05/21 13:57:22 Trace: [client/sonos] play response
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] groupandplay end
05/21 13:57:22 Trace: [client/sonos] next uri request
05/21 13:57:22 Trace: [client/sonos] next uri response
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] request matches stream, current path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, next path: /0ea760496b694208a1b099a4d2aa96ba/Roon6.flac
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] startpos is out of range, returning file headers only.  start, pos, sum, end, offset: 0, 7068618, 1158893, 352800
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction completed
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] transaction canceled, isplaying: True, did stream end: False, tx path: /0ea760496b694208a1b099a4d2aa96ba/Roon6.flac, stream path: /c1ed953f35624ecc9cefef771e7fe93e/Roon50286e8e8fb24518b9834ff8f7743a1a.flac, method: Get
05/21 13:57:22 Trace: [client/sonos] av_status
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos] state from device: PLAYING
05/21 13:57:22 Trace: [Study] [zoneplayer/sonos]  zoneplayer state: Playing
05/21 13:57:23 Info:
--[ SignalPath ]---------------------------------------------
SignalPath Quality = HighQuality
Elements:
    Source Format=Flac 44100/16/2 BitRate=473 Quality=Lossless
    UpgradeBitDepth FromBitsPerSample=16 ToBitsPerSample=64 Quality=Lossless
    VolumeNormaliation GainDb=-2.97519547416396 Quality=Enhanced
    Truncate FromBitsPerSample=64 ToBitsPerSample=16 Quality=HighQuality
    Output OutputType=Sonos Quality=Lossless SubType= Model=ONE
------------------------------------------------------------
05/21 13:57:23 Info:
--[ SignalPath ]---------------------------------------------
SignalPath Quality = HighQuality
Elements:
    Source Format=Flac 44100/16/2 BitRate=473 Quality=Lossless
    UpgradeBitDepth FromBitsPerSample=16 ToBitsPerSample=64 Quality=Lossless
    VolumeNormaliation GainDb=-2.97519547416396 Quality=Enhanced
    Truncate FromBitsPerSample=64 ToBitsPerSample=16 Quality=HighQuality
    Output OutputType=Sonos Quality=Lossless SubType= Model=ONE
------------------------------------------------------------
05/21 13:57:25 Trace: [prebuffer] short read: 0 / 8820 fill=435411  <<<< SKIPS HERE
05/21 13:57:25 Info: [stats] 3650mb Virtual, 811mb Physical, 392mb Managed, 0 Handles, 153 Threads
05/21 13:57:32 Trace: [Study] [HighQuality, 16/44 FLAC => 16/44] [24% buf] [PLAYING @ 0:02/3:54] Dearest John - Cliff Martinez / Gregory Tripi

beka · June 5, 2021, 12:52am

Hello @Leon_Roy,

I am very sorry for the delay in getting back to you. I wish we would have had the chance to do so much sooner

Thank you for all the details that you’ve shared and for marking the logs . I’ve passed them on to our technical team so they can investigate.

In the meantime, could you please confirm that this behavior happens with your local library only? Are you using any streaming services?

dylan · June 16, 2021, 8:36pm

Hi @Leon_Roy

I wanted to follow up on this and see if you were seeing this with local and streaming content as Rebeka mentioned. I am also hoping you can confirm if this happens if you play to System Output.

dylan · July 23, 2021, 12:00pm

This topic was automatically closed after 6 days. New replies are no longer allowed.