GES hangs on MPEG2 program stream files?

[Chris Wine]

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

[Thibault Saunier-4]

Hello,

There indeed is an issue using that file with GES I do not know what is going on and some debugging would be needed to determine it. Check some GST_DEBUG logs to figure it out?

- Thibault

On Fri, Jan 8, 2021 at 2:30 PM Chris Wine <[hidden email]> wrote:

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

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

[Chris Wine]

 Hi Thibault,

I'm seeing what looks like the issue right at the moment the video hangs up during playback:

0:00:10.893906600 92428 0000000007AFBD80 INFO            videodecoder gstvideodecoder.c:1310:gst_video_decoder_sink_event_default:<avdec_mpeg2video1> upstream tags: taglist, video-codec=(string)"MPEG-2\ Video\ \(Main\ Profile\)", minimum-bitrate=(uint)5235884, maximum-bitrate=(uint)58581100, bitrate=(uint)24890275;
0:00:10.894304800 92428 0000000007AFBA00 INFO                    task gsttask.c:312:gst_task_func:<mpegpsdemux2:sink> Task going to paused
0:00:10.894364200 92428 0000000007AFBD80 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <multiqueue2:src_0> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:32.195722222 on pad multiqueue2:src_0
0:00:10.894563000 92428 0000000007AFBD80 WARN            videodecoder gstvideodecoder.c:2762:gst_video_decoder_prepare_finish_frame:<avdec_mpeg2video1> decreasing timestamp (22:11:31.878733333 < 22:11:31.912100000)
0:00:10.910185800 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.193516667
0:00:10.926574600 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.210200000
0:00:10.943754500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.226883333
0:00:10.959988900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.243566667
0:00:10.976805500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.260250000
0:00:10.993280500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.276933333
0:00:11.010221900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.293616667
0:00:11.026865700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.310300000
0:00:11.043658900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.326983333
0:00:11.060436300 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.343666667
0:00:11.076939700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.360350000
0:00:11.077507800 92428 000000000386C080 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <track-element-videorate:src> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:31.917133333 on pad track-element-videorate:src
0:00:11.093741900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.377033333
0:00:11.094189300 92428 000000000386C080 INFO                    task gsttask.c:312:gst_task_func:<queue0:src> Task going to paused
0:00:11.110188200 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.393716667
0:00:11.110354600 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1320:ghost_event_probe_handler:<video_nlecomposition0> Got EOS, last EOS seqnum id : 0 current seq num is: 1287
0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652
0:00:11.110398000 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1344:ghost_event_probe_handler:<video_nlecomposition0> Got an EOS but it seqnum 1287 != next eos seqnum 652
0:00:11.110418300 92428 000000000386C840 INFO                    task gsttask.c:312:gst_task_func:<gessmartmixer0-compositor:src> Task going to paused

It seems like it is something with the EOS event perhaps getting ignored by the compositor, but I don't understand the particular error messages about EOS seqnums. Do you have any further ideas?

Thanks,

--Chris

On Fri, Jan 22, 2021 at 6:45 PM Thibault Saunier <[hidden email]> wrote:

Hello,

There indeed is an issue using that file with GES I do not know what is going on and some debugging would be needed to determine it. Check some GST_DEBUG logs to figure it out?

- Thibault

On Fri, Jan 8, 2021 at 2:30 PM Chris Wine <[hidden email]> wrote:

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

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

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

[Thibault Saunier-4]

Hi,

> 0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652

Looks like a very good hint, we should figure out who is pushing an EOS with the wrong seqnum.

- Thibault

On Fri, Feb 5, 2021 at 7:54 PM Chris Wine <[hidden email]> wrote:

 Hi Thibault,

I'm seeing what looks like the issue right at the moment the video hangs up during playback:

0:00:10.893906600 92428 0000000007AFBD80 INFO            videodecoder gstvideodecoder.c:1310:gst_video_decoder_sink_event_default:<avdec_mpeg2video1> upstream tags: taglist, video-codec=(string)"MPEG-2\ Video\ \(Main\ Profile\)", minimum-bitrate=(uint)5235884, maximum-bitrate=(uint)58581100, bitrate=(uint)24890275;
0:00:10.894304800 92428 0000000007AFBA00 INFO                    task gsttask.c:312:gst_task_func:<mpegpsdemux2:sink> Task going to paused
0:00:10.894364200 92428 0000000007AFBD80 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <multiqueue2:src_0> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:32.195722222 on pad multiqueue2:src_0
0:00:10.894563000 92428 0000000007AFBD80 WARN            videodecoder gstvideodecoder.c:2762:gst_video_decoder_prepare_finish_frame:<avdec_mpeg2video1> decreasing timestamp (22:11:31.878733333 < 22:11:31.912100000)
0:00:10.910185800 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.193516667
0:00:10.926574600 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.210200000
0:00:10.943754500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.226883333
0:00:10.959988900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.243566667
0:00:10.976805500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.260250000
0:00:10.993280500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.276933333
0:00:11.010221900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.293616667
0:00:11.026865700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.310300000
0:00:11.043658900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.326983333
0:00:11.060436300 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.343666667
0:00:11.076939700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.360350000
0:00:11.077507800 92428 000000000386C080 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <track-element-videorate:src> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:31.917133333 on pad track-element-videorate:src
0:00:11.093741900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.377033333
0:00:11.094189300 92428 000000000386C080 INFO                    task gsttask.c:312:gst_task_func:<queue0:src> Task going to paused
0:00:11.110188200 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.393716667
0:00:11.110354600 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1320:ghost_event_probe_handler:<video_nlecomposition0> Got EOS, last EOS seqnum id : 0 current seq num is: 1287
0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652
0:00:11.110398000 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1344:ghost_event_probe_handler:<video_nlecomposition0> Got an EOS but it seqnum 1287 != next eos seqnum 652
0:00:11.110418300 92428 000000000386C840 INFO                    task gsttask.c:312:gst_task_func:<gessmartmixer0-compositor:src> Task going to paused

It seems like it is something with the EOS event perhaps getting ignored by the compositor, but I don't understand the particular error messages about EOS seqnums. Do you have any further ideas?

Thanks,

--Chris

On Fri, Jan 22, 2021 at 6:45 PM Thibault Saunier <[hidden email]> wrote:

Hello,

There indeed is an issue using that file with GES I do not know what is going on and some debugging would be needed to determine it. Check some GST_DEBUG logs to figure it out?

- Thibault

On Fri, Jan 8, 2021 at 2:30 PM Chris Wine <[hidden email]> wrote:

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

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

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

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

[Chris Wine]

Hello Thibault,

I see this same message in the log for both <video_nlecomposition0> and <audio_nlecomposition1>, so it seems like it would stand to reason that the demuxer is responsible for the bad sequence numbers. Is there any way I could validate that though setting GST_DEBUG to output more detailed logging?

--Chris

On Sat, Feb 6, 2021 at 2:42 PM Thibault Saunier <[hidden email]> wrote:

Hi,

> 0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652

Looks like a very good hint, we should figure out who is pushing an EOS with the wrong seqnum.

- Thibault

On Fri, Feb 5, 2021 at 7:54 PM Chris Wine <[hidden email]> wrote:

 Hi Thibault,

I'm seeing what looks like the issue right at the moment the video hangs up during playback:

0:00:10.893906600 92428 0000000007AFBD80 INFO            videodecoder gstvideodecoder.c:1310:gst_video_decoder_sink_event_default:<avdec_mpeg2video1> upstream tags: taglist, video-codec=(string)"MPEG-2\ Video\ \(Main\ Profile\)", minimum-bitrate=(uint)5235884, maximum-bitrate=(uint)58581100, bitrate=(uint)24890275;
0:00:10.894304800 92428 0000000007AFBA00 INFO                    task gsttask.c:312:gst_task_func:<mpegpsdemux2:sink> Task going to paused
0:00:10.894364200 92428 0000000007AFBD80 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <multiqueue2:src_0> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:32.195722222 on pad multiqueue2:src_0
0:00:10.894563000 92428 0000000007AFBD80 WARN            videodecoder gstvideodecoder.c:2762:gst_video_decoder_prepare_finish_frame:<avdec_mpeg2video1> decreasing timestamp (22:11:31.878733333 < 22:11:31.912100000)
0:00:10.910185800 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.193516667
0:00:10.926574600 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.210200000
0:00:10.943754500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.226883333
0:00:10.959988900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.243566667
0:00:10.976805500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.260250000
0:00:10.993280500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.276933333
0:00:11.010221900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.293616667
0:00:11.026865700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.310300000
0:00:11.043658900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.326983333
0:00:11.060436300 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.343666667
0:00:11.076939700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.360350000
0:00:11.077507800 92428 000000000386C080 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <track-element-videorate:src> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:31.917133333 on pad track-element-videorate:src
0:00:11.093741900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.377033333
0:00:11.094189300 92428 000000000386C080 INFO                    task gsttask.c:312:gst_task_func:<queue0:src> Task going to paused
0:00:11.110188200 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.393716667
0:00:11.110354600 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1320:ghost_event_probe_handler:<video_nlecomposition0> Got EOS, last EOS seqnum id : 0 current seq num is: 1287
0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652
0:00:11.110398000 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1344:ghost_event_probe_handler:<video_nlecomposition0> Got an EOS but it seqnum 1287 != next eos seqnum 652
0:00:11.110418300 92428 000000000386C840 INFO                    task gsttask.c:312:gst_task_func:<gessmartmixer0-compositor:src> Task going to paused

It seems like it is something with the EOS event perhaps getting ignored by the compositor, but I don't understand the particular error messages about EOS seqnums. Do you have any further ideas?

Thanks,

--Chris

On Fri, Jan 22, 2021 at 6:45 PM Thibault Saunier <[hidden email]> wrote:

Hello,

There indeed is an issue using that file with GES I do not know what is going on and some debugging would be needed to determine it. Check some GST_DEBUG logs to figure it out?

- Thibault

On Fri, Jan 8, 2021 at 2:30 PM Chris Wine <[hidden email]> wrote:

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

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

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

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

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

[Chris Wine]

Thibault,

I wrote an element that wraps MainConcept's MPEGPS demuxer, and set the rank high enough so it gets chosen by uridecodebin; I'm getting the same messages in the log about wrong seqnums, so I'm starting to thing that the problem isn't with the decoder or the demuxer. I'm kind of at a loss of what to look at next. Any suggestions?

--Chris

On Mon, Feb 8, 2021 at 8:13 AM Chris Wine <[hidden email]> wrote:

Hello Thibault,

I see this same message in the log for both <video_nlecomposition0> and <audio_nlecomposition1>, so it seems like it would stand to reason that the demuxer is responsible for the bad sequence numbers. Is there any way I could validate that though setting GST_DEBUG to output more detailed logging?

--Chris

On Sat, Feb 6, 2021 at 2:42 PM Thibault Saunier <[hidden email]> wrote:

Hi,

> 0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652

Looks like a very good hint, we should figure out who is pushing an EOS with the wrong seqnum.

- Thibault

On Fri, Feb 5, 2021 at 7:54 PM Chris Wine <[hidden email]> wrote:

 Hi Thibault,

I'm seeing what looks like the issue right at the moment the video hangs up during playback:

0:00:10.893906600 92428 0000000007AFBD80 INFO            videodecoder gstvideodecoder.c:1310:gst_video_decoder_sink_event_default:<avdec_mpeg2video1> upstream tags: taglist, video-codec=(string)"MPEG-2\ Video\ \(Main\ Profile\)", minimum-bitrate=(uint)5235884, maximum-bitrate=(uint)58581100, bitrate=(uint)24890275;
0:00:10.894304800 92428 0000000007AFBA00 INFO                    task gsttask.c:312:gst_task_func:<mpegpsdemux2:sink> Task going to paused
0:00:10.894364200 92428 0000000007AFBD80 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <multiqueue2:src_0> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:32.195722222 on pad multiqueue2:src_0
0:00:10.894563000 92428 0000000007AFBD80 WARN            videodecoder gstvideodecoder.c:2762:gst_video_decoder_prepare_finish_frame:<avdec_mpeg2video1> decreasing timestamp (22:11:31.878733333 < 22:11:31.912100000)
0:00:10.910185800 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.193516667
0:00:10.926574600 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.210200000
0:00:10.943754500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.226883333
0:00:10.959988900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.243566667
0:00:10.976805500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.260250000
0:00:10.993280500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.276933333
0:00:11.010221900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.293616667
0:00:11.026865700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.310300000
0:00:11.043658900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.326983333
0:00:11.060436300 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.343666667
0:00:11.076939700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.360350000
0:00:11.077507800 92428 000000000386C080 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <track-element-videorate:src> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:31.917133333 on pad track-element-videorate:src
0:00:11.093741900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.377033333
0:00:11.094189300 92428 000000000386C080 INFO                    task gsttask.c:312:gst_task_func:<queue0:src> Task going to paused
0:00:11.110188200 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.393716667
0:00:11.110354600 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1320:ghost_event_probe_handler:<video_nlecomposition0> Got EOS, last EOS seqnum id : 0 current seq num is: 1287
0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652
0:00:11.110398000 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1344:ghost_event_probe_handler:<video_nlecomposition0> Got an EOS but it seqnum 1287 != next eos seqnum 652
0:00:11.110418300 92428 000000000386C840 INFO                    task gsttask.c:312:gst_task_func:<gessmartmixer0-compositor:src> Task going to paused

It seems like it is something with the EOS event perhaps getting ignored by the compositor, but I don't understand the particular error messages about EOS seqnums. Do you have any further ideas?

Thanks,

--Chris

On Fri, Jan 22, 2021 at 6:45 PM Thibault Saunier <[hidden email]> wrote:

Hello,

There indeed is an issue using that file with GES I do not know what is going on and some debugging would be needed to determine it. Check some GST_DEBUG logs to figure it out?

- Thibault

On Fri, Jan 8, 2021 at 2:30 PM Chris Wine <[hidden email]> wrote:

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

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

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

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

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

[Thibault Saunier-4]

Hi,

You should read the logs to figure out where that eos message comes from and see what elements created it, using a debugger/rr can also be of great helps here. I am not sure what you did exactly to try to fix the demuxer and I wouldn't be surprised if the issue comes from there.

Regards,

- Thibault

Le mar. 9 févr. 2021 à 22:25, Chris Wine <[hidden email]> a écrit :

Thibault,

I wrote an element that wraps MainConcept's MPEGPS demuxer, and set the rank high enough so it gets chosen by uridecodebin; I'm getting the same messages in the log about wrong seqnums, so I'm starting to thing that the problem isn't with the decoder or the demuxer. I'm kind of at a loss of what to look at next. Any suggestions?

--Chris

On Mon, Feb 8, 2021 at 8:13 AM Chris Wine <[hidden email]> wrote:

Hello Thibault,

I see this same message in the log for both <video_nlecomposition0> and <audio_nlecomposition1>, so it seems like it would stand to reason that the demuxer is responsible for the bad sequence numbers. Is there any way I could validate that though setting GST_DEBUG to output more detailed logging?

--Chris

On Sat, Feb 6, 2021 at 2:42 PM Thibault Saunier <[hidden email]> wrote:

Hi,

> 0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652

Looks like a very good hint, we should figure out who is pushing an EOS with the wrong seqnum.

- Thibault

On Fri, Feb 5, 2021 at 7:54 PM Chris Wine <[hidden email]> wrote:

 Hi Thibault,

I'm seeing what looks like the issue right at the moment the video hangs up during playback:

0:00:10.893906600 92428 0000000007AFBD80 INFO            videodecoder gstvideodecoder.c:1310:gst_video_decoder_sink_event_default:<avdec_mpeg2video1> upstream tags: taglist, video-codec=(string)"MPEG-2\ Video\ \(Main\ Profile\)", minimum-bitrate=(uint)5235884, maximum-bitrate=(uint)58581100, bitrate=(uint)24890275;
0:00:10.894304800 92428 0000000007AFBA00 INFO                    task gsttask.c:312:gst_task_func:<mpegpsdemux2:sink> Task going to paused
0:00:10.894364200 92428 0000000007AFBD80 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <multiqueue2:src_0> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:32.195722222 on pad multiqueue2:src_0
0:00:10.894563000 92428 0000000007AFBD80 WARN            videodecoder gstvideodecoder.c:2762:gst_video_decoder_prepare_finish_frame:<avdec_mpeg2video1> decreasing timestamp (22:11:31.878733333 < 22:11:31.912100000)
0:00:10.910185800 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.193516667
0:00:10.926574600 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.210200000
0:00:10.943754500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.226883333
0:00:10.959988900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.243566667
0:00:10.976805500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.260250000
0:00:10.993280500 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.276933333
0:00:11.010221900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.293616667
0:00:11.026865700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.310300000
0:00:11.043658900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.326983333
0:00:11.060436300 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.343666667
0:00:11.076939700 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.360350000
0:00:11.077507800 92428 000000000386C080 WARN                validate gst-validate-reporter.c:198:gst_validate_report_valist: <track-element-videorate:src> 3668 (warning) : event: a serialized event received should be pushed in the same 'time' as it was received : Serialized event eos wasn't pushed before expected timestamp 22:11:31.917133333 on pad track-element-videorate:src
0:00:11.093741900 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.377033333
0:00:11.094189300 92428 000000000386C080 INFO                    task gsttask.c:312:gst_task_func:<queue0:src> Task going to paused
0:00:11.110188200 92428 0000000007B07D80 INFO            d3dvideosink d3dhelpers.c:1953:d3d_render_buffer:<videosink-actual-sink-d3dvideo> Render 0:00:10.393716667
0:00:11.110354600 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1320:ghost_event_probe_handler:<video_nlecomposition0> Got EOS, last EOS seqnum id : 0 current seq num is: 1287
0:00:11.110380900 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:2320:_is_ready_to_restart_task:<video_nlecomposition0> WARNING: eos seqnum 1287 != wanted 652
0:00:11.110398000 92428 000000000386C840 INFO          nlecomposition nlecomposition.c:1344:ghost_event_probe_handler:<video_nlecomposition0> Got an EOS but it seqnum 1287 != next eos seqnum 652
0:00:11.110418300 92428 000000000386C840 INFO                    task gsttask.c:312:gst_task_func:<gessmartmixer0-compositor:src> Task going to paused

It seems like it is something with the EOS event perhaps getting ignored by the compositor, but I don't understand the particular error messages about EOS seqnums. Do you have any further ideas?

Thanks,

--Chris

On Fri, Jan 22, 2021 at 6:45 PM Thibault Saunier <[hidden email]> wrote:

Hello,

There indeed is an issue using that file with GES I do not know what is going on and some debugging would be needed to determine it. Check some GST_DEBUG logs to figure it out?

- Thibault

On Fri, Jan 8, 2021 at 2:30 PM Chris Wine <[hidden email]> wrote:

Hi, I'm using GStreamer/GES 1.18 on Windows, and having an issue where my GESTimeline hangs indefinitely when one of my input clips is a MPEG Program Stream file. I can also reproduce the issue with ges-launch-1.0.exe:

ges-launch-1.0.exe +clip SampleMpegProgramStream.mpg

And here is a link to the file: https://www.dropbox.com/s/vlno2iwsml71obr/SampleMpegProgramStream.mpg?dl=0

With gst-play-1.0.exe, it is able to play the file all the way through successfully. Does anyone have any insight they could share with me?

Thanks,

--Chris

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

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

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

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

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

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