CESNET / UltraGrid

UltraGrid low-latency audio and video network transmission system
http://www.ultragrid.cz
Other
492 stars 53 forks source link

Decklink: audio buffer overflow #266

Closed alatteri closed 1 year ago

alatteri commented 1 year ago

Still happening... Much less frequently than before the merge.

UltraGrid 1.7+ (tags/continuous rev 930b509 built Nov 10 2022 20:02:35)

encoder 3840x2160 12bit 24fps: UltraGrid.AppImage --tool uv -m 1316 -t decklink:device=0:codec=R12L --audio-filter delay:2:frames -c libavcodec:encoder=libsvt_hevc::la_depth=2:preset=10:pred_struct=0:gop=24:qp=20 -s embedded --audio-capture-format channels=8 --audio-codec=AAC:bitrate=256K -P 5004

receiver: uv -d decklink drift_fix --audio-delay 910 -r analog --audio-channel-map 0:0,1:1,2:2,3:3,4:4,5:5,6:6,7:7 --audio-scale none -P 5004 --param use-hw-accel,resampler=speex,decoder-use-codec=R12L

receiver log:

[2022-11-10 21:16:15] SSRC 0x58df29bc: 13184/13184 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:19] SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:19] [Audio decoder] Received 1056073/1056073 B, decoded 241667 samples in 5.03 sec.
[2022-11-10 21:16:19] [Audio decoder] Volume: [0] -13.45/-0.45, [1] -13.65/-0.40, [2] -20.62/-0.35, [3] -20.73/-3.67, [4] -17.08/-1.11, [5] -17.49/-3.36, [6] -16.42/-1.65, [7] -16.54/-1.90 dBFS RMS/peak
[2022-11-10 21:16:20] [Decklink display] 121 frames in 5.03696 seconds = 24.0224 FPS
[2022-11-10 21:16:20] SSRC 0x58df29bc: 10496/10496 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:20] Decklink stats (cumulative) - Total Audio Frames Played: 23783 / Missing Audio Frames: 4003 / Buffer Underflows: 1 / Buffer Overflows: 0 / Resample (Higher Hz): 8081 / Resample (Lower Hz): 14228 / Average Buffer: 2730 / Average Added Frames: 1454.09 / Max time diff audio (ms): 61 / Min time diff audio (ms): 1
[2022-11-10 21:16:24] SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:24] [Audio decoder] Received 870794/870794 B, decoded 239617 samples in 5.01 sec.
[2022-11-10 21:16:24] [Audio decoder] Volume: [0] -17.39/-0.48, [1] -20.17/-1.95, [2] -23.95/-6.15, [3] -30.21/-15.69, [4] -25.41/-9.09, [5] -24.77/-7.92, [6] -19.77/-3.79, [7] -20.80/-4.06 dBFS RMS/peak
[2022-11-10 21:16:24] [Decklink display] audio buffer underflow!
[2022-11-10 21:16:24] [Decklink display] audio buffer overflow! (1286 written, 762 dropped, 4714 buffer size)
[2022-11-10 21:16:24] [Decklink display] audio buffer overflow! (1485 written, 2611 dropped, 4515 buffer size)
[2022-11-10 21:16:24] [Decklink display] audio buffer overflow! (314 written, 1734 dropped, 5686 buffer size)
[2022-11-10 21:16:25] [Decklink display] 121 frames in 5.04526 seconds = 23.9829 FPS
[2022-11-10 21:16:25] [Decklink display] audio buffer overflow! (1891 written, 157 dropped, 4109 buffer size)
[2022-11-10 21:16:25] [Decklink display] audio buffer overflow! (1829 written, 219 dropped, 4171 buffer size)
[2022-11-10 21:16:25] SSRC 0x58df29bc: 6784/6784 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:25] [Decklink display] audio buffer overflow! (1818 written, 230 dropped, 4183 buffer size)
[2022-11-10 21:16:25] [Decklink display] audio buffer overflow! (1819 written, 229 dropped, 4181 buffer size)
[2022-11-10 21:16:29] SSRC 0x780bcd9b: 1792/1792 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:29] [Audio decoder] Received 983299/983299 B, decoded 240625 samples in 5.00 sec.
[2022-11-10 21:16:29] [Audio decoder] Volume: [0] -19.03/-1.99, [1] -18.73/-0.77, [2] -23.33/-2.59, [3] -26.94/-12.42, [4] -26.59/-8.80, [5] -26.53/-9.09, [6] -20.54/-3.46, [7] -20.37/-5.47 dBFS RMS/peak
[2022-11-10 21:16:30] [Decklink display] 120 frames in 5.00388 seconds = 23.9814 FPS
[2022-11-10 21:16:30] SSRC 0x58df29bc: 6656/6656 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:31] Decklink stats (cumulative) - Total Audio Frames Played: 24140 / Missing Audio Frames: 4055 / Buffer Underflows: 2 / Buffer Overflows: 7 / Resample (Higher Hz): 8113 / Resample (Lower Hz): 14520 / Average Buffer: 3240 / Average Added Frames: 1462.02 / Max time diff audio (ms): 157 / Min time diff audio (ms): 1
[2022-11-10 21:16:34] SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[2022-11-10 21:16:34] [Audio decoder] Received 1037445/1037445 B, decoded 241570 samples in 5.03 sec.
[2022-11-10 21:16:34] [Audio decoder] Volume: [0] -16.28/-0.48, [1] -16.36/-0.51, [2] -18.85/-3.67, [3] -25.74/-7.81, [4] -22.97/-7.37, [5] -23
MartinPulec commented 1 year ago

Does it occur also if you omit --audio-delay 910? The thing is that whenever it occurs on beginning and delaying audio about a second, it is quite natural. What is the minimal working example – does it occur also with uv -d decklink:drift_fix -r analog?

alatteri commented 1 year ago

Hi Martin.... I will try. But seems a few months ago, the audio and video on Decklink became wildly out of sync, much more than before, which is why I had such a high delay.

MartinPulec commented 1 year ago

But seems a few months ago, the audio and video on Decklink became wildly out of sync, much more than before, which is why I had such a high delay.

We are not aware of that. If the (video) delay is 1 second, if is be of course quite a problem as UltraGrid is marked as a low-latency SW. Isn't it caused by the _libsvthevc settings? I am not much acquainted with the options. Also that 1 second equals exactly the GOP length in your setup.

alatteri commented 1 year ago

Does it occur also if you omit --audio-delay 910? The thing is that whenever it occurs on beginning and delaying audio about a second, it is quite natural. What is the minimal working example – does it occur also with uv -d decklink:drift_fix -r analog?

Hi Martin... I've done some testing and confirm that no matter the uv options, there are buffer overflows only in times of silence, like during a countdown or slate when program has no audio, or if you pause/stop program, such as if you are playing a clip w/audio in an application and pause playback.

See the log below. Everything is fine, then I hit stop on playback in Flame application, buffer overflows, I then resume playback and Decklink goes back to normal.

This maybe expected, maybe this has not detrimental affect. My concern would be if the buffer overflow throws the sync off.

uv -d decklink:drift_fix -r analog -P 5004 --param use-hw-accel,resampler=soxr,decoder-use-codec=R12L

[Decklink display] 121 frames in 5.04176 seconds = 23.9995 FPS
SSRC 0x58df29bc: 1152/1152 packets received (100.0000%), 0 lost, max loss 0
SSRC 0x780bcd9b: 1792/1792 packets received (100.0000%), 0 lost, max loss 0
[Audio decoder] Received 711579/711579 B, decoded 239483 samples in 5.02 sec.
[Audio decoder] Volume: [0] -40.56/-24.95, [1] -43.29/-27.91, [2] -25.15/-6.75, [3] -96.19/-77.05, [4] -42.54/-26.80, [5] -45.29/-30.12, [6] -27.19/-8.37, [7] -27.43/-8.29 dBFS RMS/peak
SSRC 0x58df29bc: 8448/8448 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 121 frames in 5.04969 seconds = 23.9618 FPS
SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
Decklink stats (cumulative) - Total Audio Frames Played: 2494 / Missing Audio Frames: 445 / Buffer Underflows: 10 / Buffer Overflows: 66 / Resample (Higher Hz): 0 / Resample (Lower Hz): 2245 / Average Buffer: 3165 / Average Added Frames: 1314.11 / Max time diff audio (ms): 104 / Min time diff audio (ms): 1
[Audio decoder] Received 765695/765695 B, decoded 242597 samples in 5.03 sec.
[Audio decoder] Volume: [0] -20.82/-4.53, [1] -21.53/-4.78, [2] -24.03/-8.53, [3] -27.89/-11.52, [4] -36.66/-21.72, [5] -38.53/-22.55, [6] -22.94/-5.63, [7] -23.46/-4.36 dBFS RMS/peak
SSRC 0x58df29bc: 9984/9984 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 121 frames in 5.03783 seconds = 24.0183 FPS
SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[Audio decoder] Received 1011098/1011098 B, decoded 239569 samples in 5.01 sec.
[Audio decoder] Volume: [0] -18.65/-4.31, [1] -18.69/-4.36, [2] -21.89/-5.53, [3] -22.29/-11.38, [4] -18.47/-3.87, [5] -18.47/-3.91, [6] -17.96/-2.39, [7] -17.96/-2.50 dBFS RMS/peak
SSRC 0x58df29bc: 7680/7680 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 121 frames in 5.03458 seconds = 24.0338 FPS
SSRC 0x780bcd9b: 1792/1792 packets received (100.0000%), 0 lost, max loss 0
Decklink stats (cumulative) - Total Audio Frames Played: 2860 / Missing Audio Frames: 501 / Buffer Underflows: 10 / Buffer Overflows: 66 / Resample (Higher Hz): 0 / Resample (Lower Hz): 2611 / Average Buffer: 3005 / Average Added Frames: 1511.11 / Max time diff audio (ms): 60 / Min time diff audio (ms): 0
[Decklink display] audio buffer underflow!
[Decklink display] audio buffer overflow! (2160 written, 1936 dropped, 0 buffer size)
[Decklink display] audio buffer overflow! (925 written, 1123 dropped, 5075 buffer size)
[Decklink display] audio buffer overflow! (954 written, 70 dropped, 5046 buffer size)
[Decklink display] audio buffer overflow! (1085 written, 963 dropped, 4914 buffer size)
[Audio decoder] Received 562865/562865 B, decoded 239566 samples in 5.01 sec.
[Audio decoder] Volume: [0] -24.70/-6.54, [1] -24.81/-7.18, [2] -26.23/-7.53, [3] -27.69/-13.55, [4] -25.49/-7.33, [5] -25.52/-6.94, [6] -22.34/-3.86, [7] -22.41/-3.68 dBFS RMS/peak
SSRC 0x58df29bc: 3968/3968 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 120 frames in 5.00445 seconds = 23.9786 FPS
SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] audio buffer overflow! (2015 written, 33 dropped, 3985 buffer size)
[Decklink display] audio buffer overflow! (1793 written, 254 dropped, 4207 buffer size)
Audio dec stats (cumulative): 4359 played / 4359 total audio frames
Video dec stats (cumulative): 2232 total / 2203 disp / 29 drop / 0 corr / 0 missing.
[Decklink display] audio buffer underflow!
[Decklink display] audio buffer overflow! (2160 written, 1935 dropped, 0 buffer size)
[Decklink display] audio buffer overflow! (537 written, 1511 dropped, 5462 buffer size)
[Decklink display] audio buffer overflow! (1942 written, 106 dropped, 4058 buffer size)
[Decklink display] audio buffer overflow! (1919 written, 129 dropped, 4081 buffer size)
[Decklink display] audio buffer overflow! (1923 written, 125 dropped, 4077 buffer size)
[Audio decoder] Received 7656/7656 B, decoded 240608 samples in 5.02 sec.
[Audio decoder] Volume: [0] -inf/-inf, [1] -inf/-inf, [2] -inf/-inf, [3] -inf/-inf, [4] -inf/-inf, [5] -inf/-inf, [6] -inf/-inf, [7] -inf/-inf dBFS RMS/peak
SSRC 0x58df29bc: 1792/1792 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 121 frames in 5.04431 seconds = 23.9874 FPS
SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] audio buffer underflow!
[Decklink display] audio buffer overflow! (2160 written, 1936 dropped, 0 buffer size)
[Decklink display] audio buffer overflow! (2324 written, 1771 dropped, 3681 buffer size)
[Decklink display] audio buffer overflow! (1750 written, 298 dropped, 4249 buffer size)
[Decklink display] audio buffer overflow! (1637 written, 411 dropped, 4363 buffer size)
[Decklink display] audio buffer overflow! (1847 written, 201 dropped, 4153 buffer size)
Decklink stats (cumulative) - Total Audio Frames Played: 3167 / Missing Audio Frames: 549 / Buffer Underflows: 13 / Buffer Overflows: 82 / Resample (Higher Hz): 0 / Resample (Lower Hz): 2918 / Average Buffer: 3100 / Average Added Frames: 1670.94 / Max time diff audio (ms): 96 / Min time diff audio (ms): 2
[Audio decoder] Received 519953/519953 B, decoded 241618 samples in 5.00 sec.
[Audio decoder] Volume: [0] -27.99/-12.25, [1] -28.57/-13.17, [2] -24.66/-7.65, [3] -33.16/-19.47, [4] -35.20/-16.60, [5] -35.46/-16.62, [6] -24.84/-9.25, [7] -25.08/-9.07 dBFS RMS/peak
SSRC 0x58df29bc: 3584/3584 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 120 frames in 5.01005 seconds = 23.9519 FPS
SSRC 0x780bcd9b: 1920/1920 packets received (100.0000%), 0 lost, max loss 0
[Audio decoder] Received 704296/704296 B, decoded 241532 samples in 5.05 sec.
[Audio decoder] Volume: [0] -33.71/-19.75, [1] -35.24/-20.27, [2] -26.87/-5.79, [3] -45.79/-29.29, [4] -34.62/-21.59, [5] -36.05/-21.06, [6] -26.50/-7.97, [7] -27.17/-8.89 dBFS RMS/peak
SSRC 0x58df29bc: 6400/6400 packets received (100.0000%), 0 lost, max loss 0
[Decklink display] 121 frames in 5.03921 seconds = 24.0117 FPS
SSRC 0x780bcd9b: 1792/1792 packets received (100.0000%), 0 lost, max loss 0
Decklink stats (cumulative) - Total Audio Frames Played: 3572 / Missing Audio Frames: 622 / Buffer Underflows: 13 / Buffer Overflows: 82 / Resample (Higher Hz): 0 / Resample (Lower Hz): 3323 / Average Buffer: 2999 / Average Added Frames: 1310.1 / Max time diff audio (ms): 59 / Min time diff audio (ms): 1
[Audio decoder] Received 725805/725805 B, decoded 241567 samples in 5.01 sec.
[Audio decoder] Volume: [0] -50.29/-30.99, [1] -51.74/-34.82, [2] -25.18/-5.63, [3] -69.98/-49.10, [4] -50.15/-31.25, [5] -50.84/-33
alatteri commented 1 year ago

But seems a few months ago, the audio and video on Decklink became wildly out of sync, much more than before, which is why I had such a high delay.

We are not aware of that. If the (video) delay is 1 second, if is be of course quite a problem as UltraGrid is marked as a low-latency SW. Isn't it caused by the _libsvthevc settings? I am not much acquainted with the options. Also that 1 second equals exactly the GOP length in your setup.

I'll open another issue for this once I have more data.

alatteri commented 1 year ago

I'm closing this as the errors only seem to be exhibited during periods of silence, so doesn't really matter anyway.