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)