Test pipeline: <div class="snippet-clipboard-content notranslate position-relative

Mixing audio and video with `matroskamux` causing deadlocks,about centricular/gstcefsrc

Comments (40)

hevc commented on August 11, 2024 1

Hi,
I observe the same issue. When CPU usage is high then CEF starts producing bad audio PTS. Once the CPU usage stabilizes the audio never returns to normal. Record files then have erroneous audio. This manifests itself through very high crackling and distortion of the sound. The video looks fine. Recordings last ~1h or longer.

Moreover sometimes during low CPU usage I observe short audio crackles.

Maybe PTS calculation is wrong when gst buffer are created? Perhaps there is a PTS drift?

How to reproduce:

Create Vbox with 2 cpu.
build gst 1.21.2
build cefsrc main
start:
GST_DEBUG=3 gst-launch-1.0 -e mpegtsmux name=mux ! filesink location=test.ts cefbin name=cef cefsrc::url="https://www.youtube.com/embed/lEk1riUEdCQ?playlist=lEk1riUEdCQ&autoplay=1&loop=1" cefsrc::gpu=false cef.video ! videoconvert ! video/x-raw,framerate=30/1,format=I420 ! queue ! x264enc tune=zerolatency speed-preset=ultrafast ! h264parse ! queue ! mux. cef.audio ! queue ! audioconvert ! audiomixer ! queue ! fdkaacenc ! aacparse ! queue ! mux.

after ~10 seconds it hangs.

With vbox 4 cpu pipeline works longer but the video is bad. CPU/ Mem:

Converted with ffmpeg -i test.ts -c copy out.mp4:

out.mp4

from gstcefsrc.

philn commented on August 11, 2024 1

I experimented a bit in this branch, maybe some folks would like to give feedback! https://github.com/philn/gstcefsrc/tree/audio-things

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024 1

https://bitbucket.org/chromiumembedded/cef/issues/2995/audio-capture-susceptible-to-packet-loss#comment-59277083 sounds (hah) extremely related

from gstcefsrc.

pyldin601 commented on August 11, 2024

It is also reproducible when I run example pipeline from README.md - Record website video + audio (with audiomixer). Just need to run some CPU heavy task in the background to trigger lags. After some time of lagging, it hangs forever.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

Both pipelines work with no issue on my end (gst main). What version of GStreamer are you using? Have you tried removing either audio or video ?

from gstcefsrc.

pyldin601 commented on August 11, 2024

GStreamer 1.20.2 (GIT)

It is reproducible when cefbin starts dropping audio or video data due to CPU overload.

I've tried to remove audio/video tracks from muxer and also tried to remove cef.audio pad from audiomixer leaving only silence. In both cases, the issue was not reproducible. The only thing, that helped to make my pipeline with audio and video not hanging on overload is to make the queue between cef.audio and audiomixer leaky.

from gstcefsrc.

reinismu commented on August 11, 2024

Just a guess, but did you monitor memory usage? Maybe the queue feels up and the operating system starts to swap memory?

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

Why would cefbin drop data?

from gstcefsrc.

pyldin601 commented on August 11, 2024

Just a guess, but did you monitor memory usage? Maybe the queue feels up and the operating system starts to swap memory?

Yes, I can confirm that this happens when I have high CPU/memory usage. This causes the cefbin to start lagging. But at some point of time the pipeline completely stuck and never continues to play the pipeline. Even if CPU starts idling.

Why would cefbin drop data?

Sorry, I meant it starts lagging. But after a few seconds of lagging, the pipeline completely hangs.

Just a guess, can the "lagging" of audio/video pads on cefbin causing some pts desync on both pads?

from gstcefsrc.

philn commented on August 11, 2024

In OnAudioStreamPacket() the pts from CEF is actually not used. We compute one based on the initial video framerate, incremented by audio packet duration afterwards. I wonder why?

from gstcefsrc.

hevc commented on August 11, 2024

I tested your branch. It brings a change from the previous behavior. Audio does not drift as before (however, it needs more testing). I have attached two files for comparison: "out_new.mp4" is with the latest changes. I tested on virtualbox with 2 cpu 2.5 GHz to show the problem faster.

With the new changes you can clearly hear crackling in the audio stream. Sometimes I also heard modulations of the sound.

out_new.mp4

out_old.mp4

from gstcefsrc.

hevc commented on August 11, 2024

Maybe I'm wrong, but it looks like the audio is synchronized to the video, and it should be the other way around. Maybe the audio PTS from CEF needs to be set as the video PTS.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

In OnAudioStreamPacket() the pts from CEF is actually not used. We compute one based on the initial video framerate, incremented by audio packet duration afterwards. I wonder why?

I don't remember to be honest, but design wise my approach was: attach whatever audio was produced since the last video frame was produced, and assume CEF provides us with live, synchronized audio and video data.

from gstcefsrc.

hevc commented on August 11, 2024

I think the changes made by @philn improve a lot. The most important improvement is that using audio PTS from CEF allows the audio to fix itself after a heavy CPU load. The previous implementation had no way to fix itself.

I suggest that these changes should be merged.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

I think the patch makes sense too, but I would like to test too if you don't mind, using virtualbox is a nice trick thanks @hevc :) @pldin601 can you please try Phil's patch on your end?

I've added this to my TODO list in any case :)

from gstcefsrc.

pyldin601 commented on August 11, 2024

@pldin601 can you please try Phil's patch on your end?

Yep, going to check.

UPD. It worked much better! I heard small cracks when CPU usage was intensive, but the sound seems to be recovered rapidly. One thing I noticed - when the first audio track has ended, the next one started very quickly, and it looked like the first second of audio was played instantly.

https://drive.google.com/file/d/1V_rjj8VyP0bqgX-jRdWdMfINXDwyWpjB/view?usp=sharing

Rewind to 06:00 to hear this. Maybe that happened because there was a time gap between first and next audio tracks, but pts logic assumes that audio plays endlessly?

UPD2. Tested again my pipeline with the same test. Still freezing at random time when I compile smthng in the background...

from gstcefsrc.

philn commented on August 11, 2024

I've got a new patch in #60 -- testing welcome ;)

from gstcefsrc.

hevc commented on August 11, 2024

Audio crackles can still occur in recordings. Look at ~7s. Tested on 4x2.5 GHz.

unb.mp4

from gstcefsrc.

philn commented on August 11, 2024

Might be another bug.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

I imagine that's exactly what https://bitbucket.org/chromiumembedded/cef/issues/2995/audio-capture-susceptible-to-packet-loss#comment-59277083 is referring to. To be honest, I'm completely happy with a patch that causes us to not deadlock in these situations, if audio crackles do occur and are caused by CEF, I would conclude that:

CEF / chrome should be fixed (would be nice to know if Sean did open an issue with his proposed fix)
The user always has the option to run on a machine that is not CPU bound :)

@pldin601 can you test the updated version for freezes ?

from gstcefsrc.

reinismu commented on August 11, 2024

From what I can see the chrome issue is fixed https://chromium.googlesource.com/chromium/src/+/5b5632260b8fb40a07b350bb5a6b4e21b6bfda2e%5E%21/#F1 year and a half ago.
Assuming that we use 103.0.5060.114. It does contain those changes https://chromium.googlesource.com/chromium/src/+/refs/tags/103.0.5060.114/services/audio/owning_audio_manager_accessor.cc#123

I wonder if we should test audio crackling in isolation. (Only chrome, cef) Would help to point out where issue comes from

from gstcefsrc.

pyldin601 commented on August 11, 2024

@MathieuDuponchelle Just tested with latest @philn patch. No freezes so far. Tested a few times. Will test in application for audio cracks soon...

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

Thanks a lot for checking @reinismu :) Testing in isolation would be useful yes, for instance using the cef client example, I wonder if it was updated to also output audio.

@pldin601 that sounds like good news, were you able to reproduce reliably without the patch? If so, then I'm OK with getting the patch in, we can still keep tracking the exact source of the crackles after that.

Everyone OK with this?

from gstcefsrc.

hevc commented on August 11, 2024

@MathieuDuponchelle The cpu looked like this when the audio crackles occurred:

2.5 GHz is typical for virtual machines.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

@hevc that's good to know, can you try with the sample CEF application?

from gstcefsrc.

pyldin601 commented on August 11, 2024

@pldin601 that sounds like good news, were you able to reproduce reliably without the patch? If so, then I'm OK with getting the patch in, we can still keep tracking the exact source of the crackles after that.

After a few more retries and after tune of CPU limits, I still able to reproduce the freeze. :(

Here is another backtrace of the process when it freezes:
gdb.txt

Are we sure that those freezes are related to the cefsrc behavior or maybe it's matroska muxer bug? Why when I add "leaky" parameter to the queue it stops freezing?

UPD: Probably, I found the reason why freezes are happening.

0:00:17.459932841  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:1345:gst_collect_pads_check_collected:<collectpads0> All active pads (2 + 0 >= 2) have data, calling 0xffff72503b28
0:00:17.459937466  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:956:gst_collect_pads_peek:<collectpads0> Peeking at pad muxer:audio_0: buffer=buffer: 0xffff500136c0, pts 0:00:09.210000000, dts 99:99:99.999999999, dur 0:00:00.010000000, size 882, offset 406161, offset_end 406602, flags 0x800
0:00:17.459942591  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:956:gst_collect_pads_peek:<collectpads0> Peeking at pad muxer:video_0: buffer=buffer: 0xfffeec00d5a0, pts 0:00:09.200508583, dts 99:99:99.999999999, dur 0:00:00.033333333, size 8294400, offset none, offset_end none, flags 0x0
0:00:17.459946841  1145 0xaaab25551760 LOG              collectpads gstcollectpads.c:1573:gst_collect_pads_default_compare_func:<collectpads0> comparing 0:00:09.200508583 and 0:00:09.210000000
0:00:17.459950258  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:1481:gst_collect_pads_find_best_pad:<collectpads0> best pad video_0, best time 0:00:09.200508583
0:00:17.459954300  1145 0xaaab25551760 LOG              collectpads gstcollectpads.c:1573:gst_collect_pads_default_compare_func:<collectpads0> comparing 0:00:09.210000000 and 0:00:09.200508583
0:00:17.459957425  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:1220:gst_collect_pads_set_waiting:<collectpads0> Setting pad audio_0 to waiting 0, locked 1
0:00:17.459961675  1145 0xaaab25551760 LOG              collectpads gstcollectpads.c:1573:gst_collect_pads_default_compare_func:<collectpads0> comparing 0:00:09.200508583 and 0:00:09.200508583
0:00:17.459964633  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:1220:gst_collect_pads_set_waiting:<collectpads0> Setting pad video_0 to waiting 1, locked 1
0:00:17.459968966  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:995:gst_collect_pads_pop:<collectpads0> Pop buffer on pad muxer:video_0: buffer=buffer: 0xfffeec00d5a0, pts 0:00:09.200508583, dts 99:99:99.999999999, dur 0:00:00.033333333, size 8294400, offset none, offset_end none, flags 0x0
>>>0:00:17.459988966  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:956:gst_collect_pads_peek:<collectpads0> Peeking at pad muxer:audio_0: buffer=buffer: 0xffff500136c0, pts 0:00:09.210000000, dts 99:99:99.999999999, dur 0:00:00.010000000, size 882, offset 406161, offset_end 406602, flags 0x800<<<
0:00:17.459992883  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:956:gst_collect_pads_peek:<collectpads0> Peeking at pad muxer:video_0: buffer=(NULL)
0:00:17.459996175  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:1481:gst_collect_pads_find_best_pad:<collectpads0> best pad audio_0, best time 0:00:09.210000000
0:00:17.459999925  1145 0xaaab25551760 LOG              collectpads gstcollectpads.c:1573:gst_collect_pads_default_compare_func:<collectpads0> comparing 0:00:09.210000000 and 0:00:09.210000000
0:00:17.460003841  1145 0xaaab25551760 LOG              collectpads gstcollectpads.c:1573:gst_collect_pads_default_compare_func:<collectpads0> comparing 0:00:09.200508583 and 0:00:09.210000000
0:00:17.460007758  1145 0xaaab25551760 DEBUG            collectpads gstcollectpads.c:2235:gst_collect_pads_chain:<collectpads0> Pad muxer:audio_0 has a buffer queued, waiting
0:00:17.460028550  1145 0xaaab255514c0 DEBUG            collectpads gstcollectpads.c:2247:gst_collect_pads_chain:<collectpads0> Pad muxer:video_0 resuming

Maybe i'm wrong, but it looks like it happens because matroskamuxer awaits for a video buffer to arrive to muxer:video_0 to align it with the audio buffer that was peeked on muxer:audio_0 pad. This video buffer will never come from cef.video pad because cef element was completely blocked because audio buffers queue is full. So, pipeline has a lot of audio data, the muxer blocks pipeline on waiting for video buffer and also cef blocks pipeline on waiting for audio data to be consumed.

Probably, this happens because of audio mixer element. It produces "silence" even if cef element is lagging and this causes audio queues to overrun. That explains, why the leaky property helps. It drops audio data coming from cef when audiomixer not able to consume it in time.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

@pldin601 this is surprising, why is the audio queue going full in the first place? cefsrc should be producing video buffers on a tight schedule, as even if CEF doesn't provide it with a new frame, the old one will be reused and pushed out. We also don't even have to receive a first frame from CEF, as we zero-initialize a default first frame. cefsrc reports a fps_d / fps_n latency, so by default 1/30 second, that's far below queue's default duration, which I assume is the limit that gets triggered?

from gstcefsrc.

pyldin601 commented on August 11, 2024

@MathieuDuponchelle Yes, it's unclear for me too. Here is another pipeline where freeze 100% reproducible. I just added names to each element so the gdb backtrace was easier to debug:

  cefbin name=cef cefsrc::url="https://soundcloud.com/platform/sama" \
  audiotestsrc name=test do-timestamp=true is-live=true volume=0.0 ! audiomixer name=mixer \
  mixer. ! audioconvert name=c1 ! queue name=q1 ! matroskamux streamable=true name=muxer ! queue name=q2 ! fakesink sync=1 \
  cef.audio ! queue name=q3 ! audioconvert name=c2 ! mixer. \
  cef.video ! video/x-raw, width=1920, height=1080 ! videoconvert name=vc1 ! queue name=q4 ! muxer.

And here is gdb backtrace when pipeline was blocked:

gdb.txt

Look at Thread 5 (q4:src). It's thread of the queue between cef.video and muxer:

Thread 5 (Thread 0xffff74eee980 (LWP 162) "q4:src"):
#0  syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1  0x0000ffff79ca571c in g_cond_wait () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#2  0x0000ffff7690a5a8 in gst_queue_loop (pad=0xaaab1e6a9b30 [GstPad|src]) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1529
#3  0x0000ffff79e4ed5c in gst_task_func (task=0xaaab1e6da290 [GstTask|q4:src]) at ../subprojects/gstreamer/gst/gsttask.c:384
#4  0x0000ffff79e502bc in default_func (tdata=0xaaab1e6a3d90, pool=0xaaab1e6d8520 [GstTaskPool|taskpool0]) at ../subprojects/gstreamer/gst/gsttaskpool.c:70
#5  0x0000ffff79c88678 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#6  0x0000ffff79c859a0 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#7  0x0000ffff79a4d5c8 in start_thread (arg=0x0) at ./nptl/pthread_create.c:442
#8  0x0000ffff79ab5d1c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:79

It seems to be idle because no data in it.

Look at thread 4 (q1:src). This thread of the queue between audiomixer and muxer.

Thread 4 (Thread 0xffff756fe980 (LWP 161) "q1:src"):
#0  syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1  0x0000ffff79ca571c in g_cond_wait () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#2  0x0000ffff76b15934 in gst_collect_pads_chain (pad=0xaaab1e6a9d80 [GstPad|audio_0], parent=0xaaab1e6b6040 [GstObject|muxer], buffer=0xffff60032120) at ../subprojects/gstreamer/libs/gst/base/gstcollectpads.c:2244
#3  0x0000ffff79e07f28 in gst_pad_chain_data_unchecked (pad=0xaaab1e6a9d80 [GstPad|audio_0], type=4112, data=0xffff60032120) at ../subprojects/gstreamer/gst/gstpad.c:4447
#4  0x0000ffff79e08d18 in gst_pad_push_data (pad=0xaaab1e689c80 [GstPad|src], type=4112, data=0xffff60032120) at ../subprojects/gstreamer/gst/gstpad.c:4711
#5  0x0000ffff79e09480 in gst_pad_push (pad=0xaaab1e689c80 [GstPad|src], buffer=0xffff60032120) at ../subprojects/gstreamer/gst/gstpad.c:4830
#6  0x0000ffff76909bfc in gst_queue_push_one (queue=0xaaab1e690720 [GstQueue|q1]) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1388
#7  0x0000ffff7690a9d0 in gst_queue_loop (pad=0xaaab1e689c80 [GstPad|src]) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1541
#8  0x0000ffff79e4ed5c in gst_task_func (task=0xaaab1e6da170 [GstTask|q1:src]) at ../subprojects/gstreamer/gst/gsttask.c:384
#9  0x0000ffff79e502bc in default_func (tdata=0xaaab1e6c7dc0, pool=0xaaab1e6d8520 [GstTaskPool|taskpool0]) at ../subprojects/gstreamer/gst/gsttaskpool.c:70
#10 0x0000ffff79c88678 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#11 0x0000ffff79c859a0 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#12 0x0000ffff79a4d5c8 in start_thread (arg=0x0) at ./nptl/pthread_create.c:442
#13 0x0000ffff79ab5d1c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:79

It looks like it blocked on pushing data to the muxer's audio_0 pad.

And finally, Thread 7 of the queue between cef.audio and audiomixer:

Thread 7 (Thread 0xffff677ee980 (LWP 164) "q3:src"):
#0  syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1  0x0000ffff79ca571c in g_cond_wait () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#2  0x0000ffff76abfb58 in gst_aggregator_pad_chain_internal (self=0xaaab1e6a01d0 [GstAggregator|mixer], aggpad=0xaaab1e6d2280 [GstAggregatorPad|sink_1], buffer=0xffff5c014120, head=1) at ../subprojects/gstreamer/libs/gst/base/gstaggregator.c:3079
#3  0x0000ffff76ac03c8 in gst_aggregator_pad_chain (pad=0xaaab1e6d2280 [GstPad|sink_1], object=0xaaab1e6a01d0 [GstObject|mixer], buffer=0xffff5c014120) at ../subprojects/gstreamer/libs/gst/base/gstaggregator.c:3159
#4  0x0000ffff79e07f28 in gst_pad_chain_data_unchecked (pad=0xaaab1e6d2280 [GstPad|sink_1], type=4112, data=0xffff5c014120) at ../subprojects/gstreamer/gst/gstpad.c:4447
#5  0x0000ffff79e08d18 in gst_pad_push_data (pad=0xaaab1e6a91f0 [GstPad|src], type=4112, data=0xffff5c014120) at ../subprojects/gstreamer/gst/gstpad.c:4711
#6  0x0000ffff79e09480 in gst_pad_push (pad=0xaaab1e6a91f0 [GstPad|src], buffer=0xffff5c014120) at ../subprojects/gstreamer/gst/gstpad.c:4830
#7  0x0000ffff76b032c0 in gst_base_transform_chain (pad=0xaaab1e6a8fa0 [GstPad|sink], parent=0xaaab1e6bfd00 [GstObject|c2], buffer=0xffff5c014120) at ../subprojects/gstreamer/libs/gst/base/gstbasetransform.c:2377
#8  0x0000ffff79e07f28 in gst_pad_chain_data_unchecked (pad=0xaaab1e6a8fa0 [GstPad|sink], type=4112, data=0xffff5c014120) at ../subprojects/gstreamer/gst/gstpad.c:4447
#9  0x0000ffff79e08d18 in gst_pad_push_data (pad=0xaaab1e6a8d50 [GstPad|src], type=4112, data=0xffff5c014120) at ../subprojects/gstreamer/gst/gstpad.c:4711
#10 0x0000ffff79e09480 in gst_pad_push (pad=0xaaab1e6a8d50 [GstPad|src], buffer=0xffff5c014120) at ../subprojects/gstreamer/gst/gstpad.c:4830
#11 0x0000ffff76909bfc in gst_queue_push_one (queue=0xaaab1e690d20 [GstQueue|q3]) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1388
#12 0x0000ffff7690a9d0 in gst_queue_loop (pad=0xaaab1e6a8d50 [GstPad|src]) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1541
#13 0x0000ffff79e4ed5c in gst_task_func (task=0xaaab1e6da5f0 [GstTask|q3:src]) at ../subprojects/gstreamer/gst/gsttask.c:384
#14 0x0000ffff79e502bc in default_func (tdata=0xaaab1e6c7d80, pool=0xaaab1e6d8520 [GstTaskPool|taskpool0]) at ../subprojects/gstreamer/gst/gsttaskpool.c:70
#15 0x0000ffff79c88678 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#16 0x0000ffff79c859a0 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#17 0x0000ffff79a4d5c8 in start_thread (arg=0x0) at ./nptl/pthread_create.c:442
#18 0x0000ffff79ab5d1c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:79

It stuck on pushing data to audiomixer.

There are some "audio-queue:src" and "video-queue:src" threads, but what's the element they belong to. It is part of cefbin?

from gstcefsrc.

pyldin601 commented on August 11, 2024

Maybe the answer is somewhere in this thread:

Thread 24 (Thread 0xffff0b7ee980 (LWP 190) "cefsrc:src"):
#0  syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1  0x0000ffff79ca571c in g_cond_wait () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#2  0x0000ffff7690935c in gst_queue_chain_buffer_or_list (pad=0xaaab1e688ea0 [GstPad|sink], parent=0xaaab1e690420 [GstObject|audio-queue], obj=0xffff60044c60, is_list=0) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1251
#3  0x0000ffff76909a80 in gst_queue_chain (pad=0xaaab1e688ea0 [GstPad|sink], parent=0xaaab1e690420 [GstObject|audio-queue], buffer=0xffff60044c60) at ../subprojects/gstreamer/plugins/elements/gstqueue.c:1349
#4  0x0000ffff79e07f28 in gst_pad_chain_data_unchecked (pad=0xaaab1e688ea0 [GstPad|sink], type=4112, data=0xffff60044c60) at ../subprojects/gstreamer/gst/gstpad.c:4447
#5  0x0000ffff79e08d18 in gst_pad_push_data (pad=0xaaab1e6887b0 [GstPad|audio], type=4112, data=0xffff60044c60) at ../subprojects/gstreamer/gst/gstpad.c:4711
#6  0x0000ffff79e09480 in gst_pad_push (pad=0xaaab1e6887b0 [GstPad|audio], buffer=0xffff60044c60) at ../subprojects/gstreamer/gst/gstpad.c:4830
#7  0x0000ffff76d506dc in gst_cef_demux_push_audio_buffer(_GstBuffer**, unsigned int, AudioPushData*) () at /usr/cef/libgstcef.so
#8  0x0000ffff79dab0c4 in gst_buffer_list_foreach (list=0xfffef4059030, func=0xffff76d50620 <gst_cef_demux_push_audio_buffer(_GstBuffer**, unsigned int, AudioPushData*)>, user_data=0xffff0b7edc18) at ../subprojects/gstreamer/gst/gstbufferlist.c:280
#9  0x0000ffff76d50ba8 in gst_cef_demux_chain(_GstPad*, _GstObject*, _GstBuffer*) () at /usr/cef/libgstcef.so
#10 0x0000ffff79e07f28 in gst_pad_chain_data_unchecked (pad=0xaaab1e688310 [GstPad|sink], type=4112, data=0xffff60044a20) at ../subprojects/gstreamer/gst/gstpad.c:4447
#11 0x0000ffff79e08d18 in gst_pad_push_data (pad=0xaaab1e6880c0 [GstPad|src], type=4112, data=0xffff60044a20) at ../subprojects/gstreamer/gst/gstpad.c:4711
#12 0x0000ffff79e09480 in gst_pad_push (pad=0xaaab1e6880c0 [GstPad|src], buffer=0xffff60044a20) at ../subprojects/gstreamer/gst/gstpad.c:4830
#13 0x0000ffff76af91d8 in gst_base_src_loop (pad=0xaaab1e6880c0 [GstPad|src]) at ../subprojects/gstreamer/libs/gst/base/gstbasesrc.c:3030
#14 0x0000ffff79e4ed5c in gst_task_func (task=0xaaab1e6da950 [GstTask|cefsrc:src]) at ../subprojects/gstreamer/gst/gsttask.c:384
#15 0x0000ffff79e502bc in default_func (tdata=0xaaab1e6a3ea0, pool=0xaaab1e6d8520 [GstTaskPool|taskpool0]) at ../subprojects/gstreamer/gst/gsttaskpool.c:70
#16 0x0000ffff79c88678 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#17 0x0000ffff79c859a0 in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#18 0x0000ffff79a4d5c8 in start_thread (arg=0x0) at ./nptl/pthread_create.c:442
#19 0x0000ffff79ab5d1c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:79

It looks like audio and video from cefsrc are handled in a single thread, and gst_cef_demux_chain blocked on pushing audio data down the pipeline.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

It looks like audio and video from cefsrc are handled in a single thread, and gst_cef_demux_chain blocked on pushing audio data down the pipeline.

That is the case yes. That doesn't tell us why the audio queue runs full however, have you figured out which queue was running full exactly, and upon reaching which limit?

from gstcefsrc.

pyldin601 commented on August 11, 2024

have you figured out which queue was running full exactly, and upon reaching which limit?

I'm not sure how can I monitor queue levels with gst-launch-1.0, but according to gdb backtrace it looks like all audio queues (q1 and q3) were overrun. They have tiny capacities by default, so they can be fulfilled very fast.

UPD: I've tested last @philn patch in our application and haven't heard any audio cracks so far. Maybe I'm lucky. Possible freezes I've workarounded with a leaky queue.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

@pldin601 you can monitor queue levels with appropriately picked log levels and filtering, I can't tell you the exact command but you should be able to find the relevant filter by looking at the queue:6 logs. The other question is what limit gets triggered? Is it max-size-time ?

from gstcefsrc.

pyldin601 commented on August 11, 2024

Here's in queue logs:

0:00:28.501291013   868 0xaaaaed341760 LOG           queue_dataflow gstqueue.c:1251:gst_queue_chain_buffer_or_list:<q3> (q3:sink) wait for DEL: 18 of 0-200 buffers, 147456 of 0-10485760 bytes, 1613220875 of 0-1000000000 ns, 18 items
0:00:29.394822597   868 0xaaaaed341700 LOG           queue_dataflow gstqueue.c:1251:gst_queue_chain_buffer_or_list:<q4> (q4:sink) wait for DEL: 2 of 0-200 buffers, 16588800 of 0-10485760 bytes, 66666667 of 0-1000000000 ns, 2 items
0:00:38.594945268   868 0xaaaaed341580 LOG           queue_dataflow gstqueue.c:1251:gst_queue_chain_buffer_or_list:<q1> (q1:sink) wait for DEL: 100 of 0-200 buffers, 88200 of 0-10485760 bytes, 1000000000 of 0-1000000000 ns, 100 items

If I understood, q3 and q1 were triggered with size-time, but q4 with size-bytes.

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

The plot thickens :) If there is data in both queues feeding the muxer (q1 and q4) then why the hell is it not muxing ? :)

from gstcefsrc.

hevc commented on August 11, 2024

I found difference between main and proposed MR patch.

Run:
gst-launch-1.0 cefbin name=cef cefsrc::url=file:///home/test.html cef.video ! queue ! videoconvert ! ximagesink cef.audio ! queue ! fakesink

where test.html:

<html>
<body style="background-color:blue;">
</body>
</html>

The pipeline will show a blue screen on the main branch. The pipeline hangs on MR patch. Adding audio will unlock the MR pipeline. e.g.

<html>
<body style="background-color:blue;">
<script>
    var context = new AudioContext()
    var o = context.createOscillator()
    o.type = "sine"
    o.connect(context.destination)
    o.start()

</script>
</body>
</html>

from gstcefsrc.

MathieuDuponchelle commented on August 11, 2024

@hevc probably best to comment on the MR :)

from gstcefsrc.

philn commented on August 11, 2024

@hevc I updated the PR, please test and report issues there ;)

from gstcefsrc.

fairbairn commented on August 11, 2024

We have the same issue on the latest master using CEF_VERSION=112.3.0+gb09c4ca+chromium-112.0.5615.165.

Under heavy CPU load, the pipeline will stall and not recover. We are using an audiomixer per the example pipeline.

We'd like to determine how to get this resolved, as this is used in a commercial application.

from gstcefsrc.

SteveMcFarlin commented on August 11, 2024

I ran into this issue again today. I hacked a solution to fix my initial problem a while ago, but the issue is still there. This command will deadlock. Wait around 5 seconds and then send EOS. Note the FPS is 10.

gst-launch-1.0 -e \
    cefsrc url="https://soundcloud.com/platform/sama" ! \
    video/x-raw, width=1920, height=1080, framerate=10/1 ! \
    cefdemux name=demux ! queue ! videoconvert ! \
    queue max-size-bytes=0 max-size-buffers=0 max-size-time=3000000000 ! x264enc ! queue ! \
    mp4mux name=muxer ! filesink location='test.mp4' \
    audiotestsrc do-timestamp=true is-live=true  volume=0.0 ! audiomixer name=mix ! \
    queue max-size-bytes=0 max-size-buffers=0 max-size-time=3000000000 ! audioconvert ! \
    audiorate ! audioresample ! avenc_aac bitrate=128000 ! queue ! muxer. \
    demux. ! queue ! mix.

If this were code and you connect to the overrun signal on the audio queues you will see a lot of callbacks. Running at 30 FPS is OK(ish), and the pipeline will not deadlock at least.

Running this command is fine

gst-launch-1.0 -e \
    cefsrc url="https://soundcloud.com/platform/sama" ! \
    video/x-raw, width=1920, height=1080, framerate=10/1 ! \
    cefdemux name=demux ! queue ! videoconvert ! \
    queue max-size-bytes=0 max-size-buffers=0 max-size-time=3000000000 ! nvh264enc ! h264parse ! queue ! \
    mp4mux name=muxer ! filesink location='test.mp4' \
    audiotestsrc do-timestamp=true is-live=true  volume=0.0 ! audiomixer name=mix ! \
    queue max-size-bytes=0 max-size-buffers=0 max-size-time=3000000000 ! audioconvert ! \
    audiorate ! audioresample ! avenc_aac bitrate=128000 ! queue ! muxer. \
    demux. ! queue ! mix.

The only difference here is the the use of nvh264enc. I have not had time to dig into the debug logs. If I get a chance I will at some point.

from gstcefsrc.

SteveMcFarlin commented on August 11, 2024

I have not debug this yet, but setting threads=1 on x264enc mitigates the issue to an extent. I still see audio buffer overrun signals at regular intervals. This is certainly some issue with x264enc in the above pipeline. I also tried various muxers, and that did not make any difference. Note, I do not notice, by ear, any audio loss in the resulting file.

from gstcefsrc.

Mixing audio and video with `matroskamux` causing deadlocks about gstcefsrc HOT 40 OPEN

Comments (40)

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent