GES and qtmux 1.16.0 caps re-negotiation problem

[David Ing]

I'm on Fedora 30 running Gstreamer 1.16.0.

I've got a GESTimeline inside of a GstPipeline.  I have attached dot files which shows the pipeline immediately after each state transition.

• NULL -> READY
• READY -> PAUSED
• PAUSED -> PLAYING
• PLAYING, "JobFailed", when I receive an error message on the bus

I would have provided image files but graphviz doesn't like these dot files ... but you can use http://www.webgraphviz.com/ to visualize them.  They seem accurate except they show tee_video as disconnected (it is actually connected).

I'm attaching a "small_logs.txt" file (less verbose) and a "big_logs.txt" file (more verbose).  The interesting bits can be observed in the small file.

19-07-24T22:53:13.786414 INFO    pan CompositionJob.cpp:123 Pipeline state changed from PAUSED to PLAYING in 0.000 seconds.
19-07-24T22:53:14.120278 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120551 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120617 WARNING GST_PADS gstpad.c:4230 could not send sticky events
19-07-24T22:53:14.120740 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120822 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120896 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.137918 WARNING qtdemux qtdemux.c:6607 error: Internal data stream error.
19-07-24T22:53:14.138040 WARNING qtdemux qtdemux.c:6607 error: streaming stopped, reason not-negotiated (-4)
19-07-24T22:53:14.138201 ERROR   pan CompositionJob.cpp:282 GST_MESSAGE_ERROR received from element qtdemux5 at position 5465466666: Internal data stream error.
../gst-plugins-good/gst/isomp4/qtdemux.c(6607): gst_qtdemux_loop (): /GstPipeline:pipeline/GESTimeline:gestimeline0/GESVideoTrack:gesvideotrack0/NleComposition:video_nlecomposition1/GstBin:current-bin/NleSource:GESVideoUriSource:nlesource4/GstBin:videosrcbin/GstURIDecodeBin:uridecodebin2/GstDecodeBin:decodebin9/GstQTDemux:qtdemux5:
streaming stopped, reason not-negotiated (-4)

The job fails because of this error.  I am not sure, but it seems like there is a caps negotatiation.  The PAUSED -> PLAYING graph shows a framerate of 119/4.  By the time the job fails, many of the caps have changed to a framerate of 15/1.  So I am guessing that the caps negotiation is trying to change the framerate (all other caps are same).

My questions are:

1. Why is this happening?
2. How might I fix it?

Attachments are on google drive:

https://drive.google.com/drive/folders/19UkMHh9kV7P1JcXeYfVRsMw2jHEUEfOA?usp=sharing

TL;DR

This issue was originally posted on another email thread, but I provided logs that were incomplete.

http://gstreamer-devel.966125.n4.nabble.com/GES-1-16-0-caps-renegotiation-problem-td4691402.html

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[David Ing]

Please disregard this message.  It is a duplicate of a prior message.

On Thu, Jul 25, 2019 at 10:22 AM David Ing <[hidden email]> wrote:

I'm on Fedora 30 running Gstreamer 1.16.0.

I've got a GESTimeline inside of a GstPipeline.  I have attached dot files which shows the pipeline immediately after each state transition.

• NULL -> READY
• READY -> PAUSED
• PAUSED -> PLAYING
• PLAYING, "JobFailed", when I receive an error message on the bus

I would have provided image files but graphviz doesn't like these dot files ... but you can use http://www.webgraphviz.com/ to visualize them.  They seem accurate except they show tee_video as disconnected (it is actually connected).

I'm attaching a "small_logs.txt" file (less verbose) and a "big_logs.txt" file (more verbose).  The interesting bits can be observed in the small file.

19-07-24T22:53:13.786414 INFO    pan CompositionJob.cpp:123 Pipeline state changed from PAUSED to PLAYING in 0.000 seconds.
19-07-24T22:53:14.120278 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120551 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120617 WARNING GST_PADS gstpad.c:4230 could not send sticky events
19-07-24T22:53:14.120740 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120822 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.120896 WARNING qtmux gstqtmux.c:5118 pad video_0 refused renegotiation to video/x-h264, codec_data=(buffer)01640028ffe1001f67640028acd940780227e5c05a808080a0000003002000000303d1e30632c001000568ebecb22c, stream-format=(string)avc, alignment=(string)au, level=(string)4, profile=(string)high, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
19-07-24T22:53:14.137918 WARNING qtdemux qtdemux.c:6607 error: Internal data stream error.
19-07-24T22:53:14.138040 WARNING qtdemux qtdemux.c:6607 error: streaming stopped, reason not-negotiated (-4)
19-07-24T22:53:14.138201 ERROR   pan CompositionJob.cpp:282 GST_MESSAGE_ERROR received from element qtdemux5 at position 5465466666: Internal data stream error.
../gst-plugins-good/gst/isomp4/qtdemux.c(6607): gst_qtdemux_loop (): /GstPipeline:pipeline/GESTimeline:gestimeline0/GESVideoTrack:gesvideotrack0/NleComposition:video_nlecomposition1/GstBin:current-bin/NleSource:GESVideoUriSource:nlesource4/GstBin:videosrcbin/GstURIDecodeBin:uridecodebin2/GstDecodeBin:decodebin9/GstQTDemux:qtdemux5:
streaming stopped, reason not-negotiated (-4)

The job fails because of this error.  I am not sure, but it seems like there is a caps negotatiation.  The PAUSED -> PLAYING graph shows a framerate of 119/4.  By the time the job fails, many of the caps have changed to a framerate of 15/1.  So I am guessing that the caps negotiation is trying to change the framerate (all other caps are same).

My questions are:

1. Why is this happening?
2. How might I fix it?

Attachments are on google drive:

https://drive.google.com/drive/folders/19UkMHh9kV7P1JcXeYfVRsMw2jHEUEfOA?usp=sharing

TL;DR

This issue was originally posted on another email thread, but I provided logs that were incomplete.

http://gstreamer-devel.966125.n4.nabble.com/GES-1-16-0-caps-renegotiation-problem-td4691402.html

_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel