| Summary: | [GStreamer] Critical warnings when browsing cnn.com | ||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | WebKit | Reporter: | Michael Catanzaro <mcatanzaro> | ||||||||||||||
| Component: | Media | Assignee: | Philippe Normand <philn> | ||||||||||||||
| Status: | RESOLVED FIXED | ||||||||||||||||
| Severity: | Normal | CC: | bugs-noreply, mcatanzaro, philn, webkit-bug-importer | ||||||||||||||
| Priority: | P2 | Keywords: | InRadar | ||||||||||||||
| Version: | WebKit Nightly Build | ||||||||||||||||
| Hardware: | Unspecified | ||||||||||||||||
| OS: | Unspecified | ||||||||||||||||
| Attachments: |
|
||||||||||||||||
|
Description
Michael Catanzaro
2023-03-28 15:41:23 PDT
#7 0x00007fd9d70d73d1 in WebCore::ImageDecoderGStreamer::pushEncodedData(WebCore::FragmentedSharedBuffer const&)::$_0::operator()<WTF::GRefPtr<_GstPad> const>(WTF::GRefPtr<_GstPad> const&) const (this=<optimized out>, pad=...) at /home/mcatanzaro/Projects/WebKit/Source/WebCore/platform/graphics/gstreamer/ImageDecoderGStreamer.cpp:276
caps = {m_ptr = 0x0}
lookupResult = {isSupported = true, factory = {m_ptr = 0x1659880 [GstElementFactory|openh264dec]}}
element = {m_ptr = 0x0 [_GstElement]}
scanner = <optimized out>
_g_boolean_var_255 = <optimized out>
I think gdb is fooling you here. The vars mentioned have been WTFMoved away, so it's normal that their m_ptr is 0x0...
I can't trigger the image decoder here when browsing "cnn.com" so please, either: - provide a debug log GST_DEBUG="3,webkitelementharness:9,webkitimage*:8" - or share a specific URL triggering the issue, not a TLD. https://cnn.com/ is the specific URL that triggers this issue. I'll get a debug log. Created attachment 465658 [details]
Debug log
I noticed that it's a *lot* harder to trigger this crash today than it was yesterday, but it still happens. Just takes a lot longer.
(In reply to Michael Catanzaro from comment #4) > Created attachment 465658 [details] > Debug log > > I noticed that it's a *lot* harder to trigger this crash today than it was > yesterday, but it still happens. Just takes a lot longer. Did it really happen? I see no duplicate caps event logged... The only caps event I see in the log is pushEvent:<image-decoder-parser-0> Pushing caps event: 0x1d0bb20, time 99:99:99.999999999, seq-num 12794, GstEventCaps, caps=(GstCaps)"video/quicktime\,\ variant\=\(string\)iso"; which afaict represents fixed caps... (In reply to Philippe Normand from comment #5) > Did it really happen? I see no duplicate caps event logged... I have a crash in coredumpctl one minute before I uploaded that log to Bugzilla and it's crashing inside gst_event_new_caps, so yeah, I'd say that log corresponds to this issue. Is "pushing caps event" logged before or after gst_event_new_caps() is called? Probably after? Then it's expected that it doesn't get that far. bool GStreamerElementHarness::pushEvent(GRefPtr<GstEvent>&& event)
{
GST_TRACE_OBJECT(m_element.get(), "Pushing %" GST_PTR_FORMAT, event.get());
auto result = gst_pad_push_event(m_srcPad.get(), event.leakRef());
GST_TRACE_OBJECT(m_element.get(), "Result: %s", boolForPrinting(result));
return result;
}
We do emit a trace message *before* pushing.
Ahh gst_event_new_caps() is what fails... sorry. Ok, add GST_EVENT:4 in GST_DEBUG and we should have a better log please. Sorry again Well, not going to be useful either...
GstEvent *
gst_event_new_caps (GstCaps * caps)
{
GstEvent *event;
g_return_val_if_fail (caps != NULL, NULL);
g_return_val_if_fail (gst_caps_is_fixed (caps), NULL);
GST_CAT_INFO (GST_CAT_EVENT, "creating caps event %" GST_PTR_FORMAT, caps);
...
I will try to unset G_DEBUG=fatal-criticals and see if I can catch it again. Maybe that would be helpful. Can you add qtdemux:8 to GST_DEBUG? I suspect the input data is a mp4 with more than one track and we're hitting a racy behavior when the demuxer adds its source pads... Also which GStreamer version is this? GStreamer 1.22.1 OK, sorry for the delay. I'm attaching a debug log taken with: $ jhbuild run env G_DEBUG= WEBKIT_DISABLE_SANDBOX_THIS_IS_DANGEROUS=1 GST_DEBUG="3,webkitelementharness:9,webkitimage*:8,qtdemux:8" GST_DEBUG_FILE="$HOME/gst.log" GST_DEBUG_NO_COLOR=1 ~/Projects/GNOME/install/libexec/webkitgtk-6.0/MiniBrowser https://cnn.com (WebKitWebProcess:680298): GStreamer-CRITICAL **: 13:59:14.786: gst_event_new_caps: assertion 'gst_caps_is_fixed (caps)' failed (WebKitWebProcess:680298): GStreamer-CRITICAL **: 13:59:14.786: gst_pad_push_event: assertion 'GST_IS_EVENT (event)' failed (WebKitWebProcess:680298): GStreamer-WARNING **: 13:59:14.787: ../gst/gstpad.c:5366:store_sticky_event:<'':src> Sticky event misordering, got 'segment' before 'caps' (WebKitWebProcess:680298): GStreamer-WARNING **: 13:59:14.787: ../gst/gstpad.c:5366:store_sticky_event:<openh264dec4:sink> Sticky event misordering, got 'segment' before 'caps' (WebKitWebProcess:680298): GStreamer-CRITICAL **: 13:59:14.805: gst_event_new_caps: assertion 'gst_caps_is_fixed (caps)' failed (WebKitWebProcess:680298): GStreamer-CRITICAL **: 13:59:14.805: gst_pad_push_event: assertion 'GST_IS_EVENT (event)' failed (WebKitWebProcess:680298): GStreamer-WARNING **: 13:59:14.806: ../gst/gstpad.c:5366:store_sticky_event:<'':src> Sticky event misordering, got 'segment' before 'caps' (WebKitWebProcess:680298): GStreamer-WARNING **: 13:59:14.806: ../gst/gstpad.c:5366:store_sticky_event:<openh264dec5:sink> Sticky event misordering, got 'segment' before 'caps' (WebKitWebProcess:680298): GStreamer-CRITICAL **: 13:59:14.825: gst_event_new_caps: assertion 'gst_caps_is_fixed (caps)' failed (WebKitWebProcess:680298): GStreamer-CRITICAL **: 13:59:14.825: gst_pad_push_event: assertion 'GST_IS_EVENT (event)' failed (WebKitWebProcess:680298): GStreamer-WARNING **: 13:59:14.826: ../gst/gstpad.c:5366:store_sticky_event:<'':src> Sticky event misordering, got 'segment' before 'caps' (WebKitWebProcess:680298): GStreamer-WARNING **: 13:59:14.826: ../gst/gstpad.c:5366:store_sticky_event:<openh264dec6:sink> Sticky event misordering, got 'segment' before 'caps' Created attachment 465684 [details]
Another debug log
I see my old friend openh264dec returning not-negotiated... Can you try this? http://sprunge.us/IzQZnR (In reply to Philippe Normand from comment #18) > I see my old friend openh264dec returning not-negotiated... Can you try > this? http://sprunge.us/IzQZnR I think that fixes it (but not certain). Thanks. Pull request: https://github.com/WebKit/WebKit/pull/12290 (In reply to Philippe Normand from comment #20) > Pull request: https://github.com/WebKit/WebKit/pull/12290 Can you test this please? Unfortunately this is not fixed by #12290. It's possible that I got unlucky and failed to reproduce the problem by chance when testing the patch from comment #18. Or perhaps that patch was good but #12290 is not. I'll attach a backtrace taken with #12290 applied. Created attachment 465750 [details]
Newer backtrace
Can you provide a debug log please? I still can't reproduce this after: 1. switching to a VPN in the US (europe doesn't get the same cnn.com) 2. disabling the jpeg xl support 3. disabling avdec_h264 4. updating to openh264 2.3.1 The image decoder is never tricked here... So we'd need a use-case, can you download the mp4 file that fails to render in the image tag? There is a debug log in comment #17. I can no longer easily reproduce it on the homepage, but can still reproduce by visiting article pages, e.g. loading https://www.cnn.com/travel/article/italy-tourist-restrictions-alto-adige/index.html seems to reliably reproduce the crash. Mucking around in the web inspector, I was able to download two mp4 files that both appear to be malformed, but I have no clue if they are used in img tags or if they are related to this bug. Created attachment 465932 [details]
weird mp4
Created attachment 465933 [details]
another weird mp4
I have a reliable test-case now. The trick was to disable my pihole, the issue happens only in ads rendering, with openh264dec... Committed 263134@main (c94b3642944f): <https://commits.webkit.org/263134@main> Reviewed commits have been landed. Closing PR #12290 and removing active labels. |