[PATCH 0/1] MR7823: winegstreamer: Allow decodebin to eliminate caps that don't use system memory.
This speeds up pipeline creation and fixes a timing issue where caps negotiation is not completed prior to the first buffer being sent.
From: Brendan McGrath bmcgrath@codeweavers.com
This speeds up pipeline creation and fixes a timing issue where caps negotiation is not completed prior to the first buffer being sent. --- dlls/winegstreamer/wg_parser.c | 33 +++++++++++++++++++++++++++++++++ 1 file changed, 33 insertions(+)
diff --git a/dlls/winegstreamer/wg_parser.c b/dlls/winegstreamer/wg_parser.c index 710cfe6a0a5..56d4e102a22 100644 --- a/dlls/winegstreamer/wg_parser.c +++ b/dlls/winegstreamer/wg_parser.c @@ -555,6 +555,38 @@ static GstAutoplugSelectResult autoplug_select_cb(GstElement *bin, GstPad *pad, return GST_AUTOPLUG_SELECT_TRY; }
+static gboolean autoplug_query_cb(GstElement *bin, GstPad *child, + GstElement *pad, GstQuery *query, gpointer user) +{ + GstCapsFeatures *features; + GstCaps *filter, *result; + GstStructure *structure; + guint i; + + GST_INFO("Query %"GST_PTR_FORMAT, query); + + if (query->type == GST_QUERY_CAPS) + { + result = gst_caps_new_empty(); + gst_query_parse_caps(query, &filter); + for (i = 0; i < gst_caps_get_size(filter); i++) + { + if (!(features = gst_caps_get_features(filter, i)) || gst_caps_features_contains(features, GST_CAPS_FEATURE_MEMORY_SYSTEM_MEMORY)) + { + structure = gst_caps_get_structure(filter, i); + gst_caps_append_structure(result, gst_structure_copy(structure)); + } + } + + GST_INFO("Result %"GST_PTR_FORMAT, result); + gst_query_set_caps_result(query, result); + + return TRUE; + } + + return FALSE; +} + static void no_more_pads_cb(GstElement *element, gpointer user) { struct wg_parser *parser = user; @@ -1802,6 +1834,7 @@ static BOOL decodebin_parser_init_gst(struct wg_parser *parser) g_signal_connect(element, "pad-removed", G_CALLBACK(pad_removed_cb), parser); g_signal_connect(element, "autoplug-continue", G_CALLBACK(autoplug_continue_cb), parser); g_signal_connect(element, "autoplug-select", G_CALLBACK(autoplug_select_cb), parser); + g_signal_connect(element, "autoplug-query", G_CALLBACK(autoplug_query_cb), parser); g_signal_connect(element, "no-more-pads", G_CALLBACK(no_more_pads_cb), parser); g_signal_connect(element, "deep-element-added", G_CALLBACK(deep_element_added_cb), parser);
This speeds up pipeline creation
That makes sense...
and fixes a timing issue where caps negotiation is not completed prior to the first buffer being sent.
but that seems very wrong. GStreamer is, by law, supposed to send caps before any buffers. What's going on here exactly?
On Wed Apr 16 02:04:12 2025 +0000, Elizabeth Figura wrote:
This speeds up pipeline creation
That makes sense...
and fixes a timing issue where caps negotiation is not completed prior
to the first buffer being sent. but that seems very wrong. GStreamer is, by law, supposed to send caps before any buffers. What's going on here exactly?
That's a good question. I'll dig deeper.
On Wed Apr 16 02:04:12 2025 +0000, Brendan McGrath wrote:
That's a good question. I'll dig deeper.
I still haven't got to the bottom of this. But if I run the following pipeline:
``` gst-launch-1.0 filesrc location=test.mp4 ! decodebin ! deinterlace ! videoconvert ! videoflip ! videoconvert ! autovideosink ```
The logs show: ``` 0:00:01.567916117 218191 0x74a258000ee0 DEBUG GST_CAPS gstpad.c:2768:gst_pad_get_current_caps:nvh264dec0:src get current pad caps video/x-raw(memory:CUDAMemory), format=(string)NV12, width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, colorimetry=(string)bt709, framerate=(fraction)30/1
0:00:01.540485289 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.033333333, DTS 0:00:00.000000000 duration 0:00:00.033333333 size 486 flags 640 0:00:01.556290749 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.133333333, DTS 0:00:00.033333333 duration 0:00:00.033333333 size 74 flags 2200 0:00:01.557091898 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.066666666, DTS 0:00:00.066666666 duration 0:00:00.033333333 size 71 flags 2200 0:00:01.558826743 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.100000000, DTS 0:00:00.100000000 duration 0:00:00.033333333 size 72 flags 2200 0:00:01.560370298 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.233333333, DTS 0:00:00.133333333 duration 0:00:00.033333333 size 74 flags 2200 0:00:01.562026455 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.166666666, DTS 0:00:00.166666666 duration 0:00:00.033333333 size 72 flags 2200
0:00:01.609126177 218191 0x74a258000ee0 DEBUG GST_CAPS gstpad.c:2768:gst_pad_get_current_caps:nvh264dec0:src get current pad caps video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, colorimetry=(string)bt709, framerate=(fraction)30/1
0:00:01.614464770 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.200000000, DTS 0:00:00.200000000 duration 0:00:00.033333333 size 72 flags 2200 0:00:01.679946139 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.333333333, DTS 0:00:00.233333333 duration 0:00:00.033333333 size 74 flags 2200 0:00:01.713060659 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.266666666, DTS 0:00:00.266666666 duration 0:00:00.033333333 size 72 flags 2200 0:00:01.780730625 218191 0x74a258000ee0 LOG videodecoder gstvideodecoder.c:2780:gst_video_decoder_chain:<nvh264dec0> chain PTS 0:00:00.300000000, DTS 0:00:00.300000000 duration 0:00:00.033333333 size 72 flags 2200 ```
So you can see there are 6 samples delivered to `nvh264dec0` before it settles on the caps without the `memory:CUDAMemory` feature. I think this is because `nvh264dec0` is right on the edge of the decode bin (I've attached the pipeline layout).
[0.00.01.315809344-gst-launch.READY_PAUSED.dot](/uploads/657997a270439e630d615d0cbdf2ebac/0.00.01.315809344-gst-launch.READY_PAUSED.dot)
But with Wine, I can see the `memory:CUDAMemory` feature is still in use when we forward buffers outside of the `decodebin` and we end up with the following errors: ``` 0:00:01.367038957 209283 0x7020700013a0 WARN basetransform gstbasetransform.c:1371:gst_base_transform_setcaps:<videoconvert0> transform could not transform video/x-raw(memory:CUDAMemory), format=(string)NV12, width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, colorimetry=(string)bt709, framerate=(fraction)30/1 in anything we support 0:00:01.367052022 209283 0x7020700013a0 DEBUG GST_PADS gstpad.c:5986:gst_pad_send_event_unchecked:videoconvert0:sink sent event, ret not-negotiated 0:00:01.373114496 209283 0x7020700013a0 DEBUG GST_SCHEDULING gstpad.c:4496:gst_pad_chain_data_unchecked:deinterlace0:sink called chainfunction &gst_deinterlace_chain with buffer 0x70205c012fd0, returned not-negotiated ```
So the two things I'm still unsure about is: 1. Why does it sometimes work under Wine; and 2. Why does it always work with `gst-launch-1.0`
- Why does it sometimes work under Wine
I found that when Wine succeeds, we get the following entry logged: ``` gstnvdecoder.cpp:851:gst_nv_decoder_output_picture:<nvh264dec0> Negotiate again on reconfigure ```
This is a the result of the `GST_PAD_FLAG_NEED_RECONFIGURE` flag being set on the `nvh264dec0:src` pad when it tries to push a buffer. That flag is set when we link `decodebin0` to `deinterlace0`. But the pipeline processing begins as soon as `decodebin0` finishes linking internally. So the order in which the reconfigure flag is set and when a buffer is sent is indeterminable (thus sometimes it works, sometimes it doesn't).
- Why does it always work with `gst-launch-1.0`
The simple answer is timing. If I apply the following patch:
[gstreamer.patch](/uploads/8c5dd45b70be7f4fda8957daf53cb04c/gstreamer.patch)
then `gst-launch-1.0` fails 100% of the time. This patch just delays the setting of the reconfigure flag by 10ms.
However, even with this delay, when this MR is applied to Wine, Wine will succeed 100% of the time (as it has no need to reconfigure).
On Thu Apr 17 07:07:45 2025 +0000, Brendan McGrath wrote:
- Why does it sometimes work under Wine
I found that when Wine succeeds, we get the following entry logged:
gstnvdecoder.cpp:851:gst_nv_decoder_output_picture:<nvh264dec0> Negotiate again on reconfigureThis is a the result of the `GST_PAD_FLAG_NEED_RECONFIGURE` flag being set on the `nvh264dec0:src` pad when it tries to push a buffer. That flag is set when we link `decodebin0` to `deinterlace0`. But the pipeline processing begins as soon as `decodebin0` finishes linking internally. So the order in which the reconfigure flag is set and when a buffer is sent is indeterminable (thus sometimes it works, sometimes it doesn't).
- Why does it always work with `gst-launch-1.0`
The simple answer is timing. If I apply the following patch: [gstreamer.patch](/uploads/8c5dd45b70be7f4fda8957daf53cb04c/gstreamer.patch) then `gst-launch-1.0` fails 100% of the time. This patch just delays the setting of the reconfigure flag by 10ms. However, even with this delay, when this MR is applied to Wine, Wine will succeed 100% of the time (as it has no need to reconfigure).
Since we are immediately doing a reconfigure, is the not-negotiated error actually a problem, or is it just transient?
However, even with this delay, when this MR is applied to Wine, Wine will succeed 100% of the time (as it has no need to reconfigure).
I'm confused, you just said we are doing a reconfigure, and we should be if we're linking a new pad?
Since we are immediately doing a reconfigure, is the not-negotiated error actually a problem, or is it just transient?
`qtdemux` treats it as a fatal error. Here's an extract from a log when running `gst-launch-1.0` using the pipeline above with the 10ms delay: ``` 0:00:02.048477330 102414 0x73d7ec000d20 WARN qtdemux qtdemux.c:7423:gst_qtdemux_loop:<qtdemux0> error: Internal data stream error. 0:00:02.048486424 102414 0x73d7ec000d20 WARN qtdemux qtdemux.c:7423:gst_qtdemux_loop:<qtdemux0> error: streaming stopped, reason not-negotiated (-4) 0:00:02.048528816 102414 0x73d7ec000d20 INFO GST_ERROR_SYSTEM gstelement.c:2281:gst_element_message_full_with_details:<qtdemux0> posting message: Internal data stream error. 0:00:02.048623751 102414 0x73d7ec000d20 DEBUG decodebin gstdecodebin2.c:5684:gst_decode_bin_handle_message:<decodebin0> Forwarding msg error message: 0x73d7e4abd610, time 99:99:99.999999999, seq-num 229, element 'qtdemux0', GstMessageError, gerror=(GError)NULL, debug=(string)"../subprojects/gst-plugins-good/gst/isomp4/qtdemux.c(7423):\ gst_qtdemux_loop\ ():\ /GstPipeline:pipeline0/GstDecodeBin:decodebin0/GstQTDemux:qtdemux0:\012streaming\ stopped,\ reason\ not-negotiated\ (-4)", details=(structure)"details,\ flow-return=(int)-4;"; 0:00:02.088273677 102414 0x5efd2df1f8b0 DEBUG GST_STATES gstelement.c:3045:gst_element_set_state_func:<qtdemux0> final: setting state from PAUSED to READY 0:00:02.088279546 102414 0x5efd2df1f8b0 DEBUG GST_ELEMENT_PADS gstelement.c:3245:gst_element_pads_activate:<qtdemux0> deactivate pads 0:00:02.088285486 102414 0x5efd2df1f8b0 DEBUG GST_PADS gstpad.c:1120:gst_pad_set_active:qtdemux0:video_0 deactivating pad from push mode 0:00:02.088287607 102414 0x5efd2df1f8b0 DEBUG GST_PADS gstpad.c:991:pre_activate:qtdemux0:video_0 setting PAD_MODE NONE, set flushing 0:00:02.088290570 102414 0x5efd2df1f8b0 DEBUG GST_PADS gstpad.c:1054:post_activate:qtdemux0:video_0 stopped streaming 0:00:02.088859827 102414 0x5efd2df1f8b0 DEBUG task gsttask.c:744:gst_task_set_state_unlocked:qtdemux0:sink Changing task 0x73d7e8002e20 to state stopped 0:00:02.089164708 102414 0x5efd2df1f8b0 INFO GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<qtdemux0> removing pad 'video_0'
```
I'm confused, you just said we are doing a reconfigure, and we should be if we're linking a new pad?
The issue is that the initial caps neg (which occurs internal to `decodebin`) ends on agreeing with `video/x-raw(memory:CUDAMemory)` (the proxy within `decodebin` accepts `ANY` caps). However, when you link `deinterlace0` to `decodebin`, that triggers a `GST_EVENT_RECONFIGURE` event. The `GST_EVENT_RECONFIGURE` event travels upstream whilst the buffers travel downstream; hence they are not synced in any fashion. The order in which they arrive is indeterminable.
The reconfigure results in us choosing `video/x-raw` (which doesn't have the `memory:CUDAMemory` feature). Thus it'll work if the reconfigure arrives first (which is why it sometimes works under Wine now, as the event can sometimes arrive before the buffer).
The change I'm making now means the initial caps neg (again, internal to `decodebin`) never uses the `memory:CUDAMemory` feature (it's rejected by `autoplug_query_cb`). Hence it doesn't matter if a reconfigure occurs first or not. As the reconfigure won't change the agreed caps.
On Wed Apr 23 02:31:48 2025 +0000, Brendan McGrath wrote:
Since we are immediately doing a reconfigure, is the not-negotiated
error actually a problem, or is it just transient? `qtdemux` treats it as a fatal error. Here's an extract from a log when running `gst-launch-1.0` using the pipeline above with the 10ms delay:
0:00:02.048477330 102414 0x73d7ec000d20 WARN qtdemux qtdemux.c:7423:gst_qtdemux_loop:<qtdemux0> error: Internal data stream error. 0:00:02.048486424 102414 0x73d7ec000d20 WARN qtdemux qtdemux.c:7423:gst_qtdemux_loop:<qtdemux0> error: streaming stopped, reason not-negotiated (-4) 0:00:02.048528816 102414 0x73d7ec000d20 INFO GST_ERROR_SYSTEM gstelement.c:2281:gst_element_message_full_with_details:<qtdemux0> posting message: Internal data stream error. 0:00:02.048623751 102414 0x73d7ec000d20 DEBUG decodebin gstdecodebin2.c:5684:gst_decode_bin_handle_message:<decodebin0> Forwarding msg error message: 0x73d7e4abd610, time 99:99:99.999999999, seq-num 229, element 'qtdemux0', GstMessageError, gerror=(GError)NULL, debug=(string)"../subprojects/gst-plugins-good/gst/isomp4/qtdemux.c\(7423\):\ gst_qtdemux_loop\ \(\):\ /GstPipeline:pipeline0/GstDecodeBin:decodebin0/GstQTDemux:qtdemux0:\012streaming\ stopped\,\ reason\ not-negotiated\ \(-4\)", details=(structure)"details\,\ flow-return\=\(int\)-4\;"; 0:00:02.088273677 102414 0x5efd2df1f8b0 DEBUG GST_STATES gstelement.c:3045:gst_element_set_state_func:<qtdemux0> final: setting state from PAUSED to READY 0:00:02.088279546 102414 0x5efd2df1f8b0 DEBUG GST_ELEMENT_PADS gstelement.c:3245:gst_element_pads_activate:<qtdemux0> deactivate pads 0:00:02.088285486 102414 0x5efd2df1f8b0 DEBUG GST_PADS gstpad.c:1120:gst_pad_set_active:<qtdemux0:video_0> deactivating pad from push mode 0:00:02.088287607 102414 0x5efd2df1f8b0 DEBUG GST_PADS gstpad.c:991:pre_activate:<qtdemux0:video_0> setting PAD_MODE NONE, set flushing 0:00:02.088290570 102414 0x5efd2df1f8b0 DEBUG GST_PADS gstpad.c:1054:post_activate:<qtdemux0:video_0> stopped streaming 0:00:02.088859827 102414 0x5efd2df1f8b0 DEBUG task gsttask.c:744:gst_task_set_state_unlocked:<qtdemux0:sink> Changing task 0x73d7e8002e20 to state stopped 0:00:02.089164708 102414 0x5efd2df1f8b0 INFO GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<qtdemux0> removing pad 'video_0'I'm confused, you just said we are doing a reconfigure, and we should
be if we're linking a new pad? The issue is that the initial caps neg (which occurs internal to `decodebin`) ends on agreeing with `video/x-raw(memory:CUDAMemory)` (the proxy within `decodebin` accepts `ANY` caps). However, when you link `deinterlace0` to `decodebin`, that triggers a `GST_EVENT_RECONFIGURE` event. The `GST_EVENT_RECONFIGURE` event travels upstream whilst the buffers travel downstream; hence they are not synced in any fashion. The order in which they arrive is indeterminable. The reconfigure results in us choosing `video/x-raw` (which doesn't have the `memory:CUDAMemory` feature). Thus it'll work if the reconfigure arrives first (which is why it sometimes works under Wine now, as the event can sometimes arrive before the buffer). The change I'm making now means the initial caps neg (again, internal to `decodebin`) never uses the `memory:CUDAMemory` feature (it's rejected by `autoplug_query_cb`). Hence it doesn't matter if a reconfigure occurs first or not. As the reconfigure won't change the agreed caps.
I'll add one more thing. In all three cases, the `GST_EVENT_CAPS` event is still being sent downstream and in-band, but its only in the case that `decodebin` is still using the `memory:CUDAMemory` feature that we get the `not-negotiated` error (this is the log from one of my earlier comments, which shows the error scenario):
``` 0:00:01.367038957 209283 0x7020700013a0 WARN basetransform gstbasetransform.c:1371:gst_base_transform_setcaps:<videoconvert0> transform could not transform video/x-raw(memory:CUDAMemory), format=(string)NV12, width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, colorimetry=(string)bt709, framerate=(fraction)30/1 in anything we support 0:00:01.367052022 209283 0x7020700013a0 DEBUG GST_PADS gstpad.c:5986:gst_pad_send_event_unchecked:videoconvert0:sink sent event, ret not-negotiated 0:00:01.373114496 209283 0x7020700013a0 DEBUG GST_SCHEDULING gstpad.c:4496:gst_pad_chain_data_unchecked:deinterlace0:sink called chainfunction &gst_deinterlace_chain with buffer 0x70205c012fd0, returned not-negotiated
```
The three cases I'm referring to being: 1. The buffer arrives before the RECONFIGURE event (hence we're still using the `memory:CUDAMemory` feature and we get the error); 2. The RECONFIGURE event occurs prior to the buffer (in which case we've negotiated away the the `memory:CUDAMemory` feature and the new caps is accepted); and 3. The `memory:CUDAMemory` feature is rejected by `autoplug_query_cb`; added in this MR (hence the caps sent either side of the RECONFIGURE event is accepted)
On Wed Apr 23 03:51:34 2025 +0000, Brendan McGrath wrote:
I'll add one more thing. In all three cases, the `GST_EVENT_CAPS` event is still being sent downstream and in-band, but its only in the case that `decodebin` is still using the `memory:CUDAMemory` feature that we get the `not-negotiated` error (this is the log from one of my earlier comments, which shows the error scenario):
0:00:01.367038957 209283 0x7020700013a0 WARN basetransform gstbasetransform.c:1371:gst_base_transform_setcaps:<videoconvert0> transform could not transform video/x-raw(memory:CUDAMemory), format=(string)NV12, width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, colorimetry=(string)bt709, framerate=(fraction)30/1 in anything we support 0:00:01.367052022 209283 0x7020700013a0 DEBUG GST_PADS gstpad.c:5986:gst_pad_send_event_unchecked:<videoconvert0:sink> sent event, ret not-negotiated 0:00:01.373114496 209283 0x7020700013a0 DEBUG GST_SCHEDULING gstpad.c:4496:gst_pad_chain_data_unchecked:<deinterlace0:sink> called chainfunction &gst_deinterlace_chain with buffer 0x70205c012fd0, returned not-negotiatedThe three cases I'm referring to being:
- The buffer arrives before the RECONFIGURE event (hence we're still
using the `memory:CUDAMemory` feature and we get the error); 2. The RECONFIGURE event occurs prior to the buffer (in which case we've negotiated away the the `memory:CUDAMemory` feature and the new caps is accepted); and 3. The `memory:CUDAMemory` feature is rejected before linking by `autoplug_query_cb`; added in this MR (hence the caps sent either side of the RECONFIGURE event is accepted)
Sorry about the delay, and thank you for the investigation. I wanted to get a clearer picture of the GStreamer bug, but I think it's clear that it is one, and this seems like a reasonable way to work around it regardless of where the fault ultimately lies.
There is a very long line introduced by the patch; please break it before the "||".
Please also adjust the commit message to read:
"nvh264dec fixates a caps using CUDAMemory, which is not accepted by deinterlace. Linking triggers a reconfigure, but due to a GStreamer bug some buffers are sent with the CUDAMemory caps, triggering a streaming error. Work around this by forcing all buffers to use system memory."
On investigation I don't think I see how pipeline creation is going to be sped up, since we always trigger a reconfigure anyway?
-
Brendan McGrath -
Brendan McGrath (＠redmcg)
-
Elizabeth Figura (＠zfigura)