GStreamer-devel

Trying to diagnose a READY --> PAUSED transition bug

Classic

List

Threaded

6 messages Options

David Ing

Trying to diagnose a READY --> PAUSED transition bug

I am using Gstreamer 1.14.4. I am having an issue with one of my pipelines on Windows. I attached an SVG file which shows my pipeline at the point in time when it gets stuck. The issue occurs when I try to move my pipeline from READY to PAUSED. I do this by calling gst_element_set_state(gstPipeline, GST_STATE_PAUSED), and after that call is made, I see all elements within the pipeline transition to PAUSED except the GstFileSink which remains stuck in READY.

Also:

The issue does not repro on Linux (only Windows).
I use the same basic code to render many other kinds of jobs and I never have a problem with the GstFileSink. It is only for this one specific pipeline that I have the problem.
I am 100% certain that this isn't some kind of file system issue (e.g. folder permissions).

For logging I set the the "filesink" category to TRACE and this is the entirety of what it shows me:

Pipeline is in NULL state, as I connect the muxer to the filesink I see this:

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:294 filename : C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4
19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:295 uri : file:///C:/dev/github/panopto/panopto-core/Debug/x64/test-scratch/2019-03-25T20-44-11.942351/CompositionTests/Debug/0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

Immediately after I call gst_element_set_state(gstPipeline, GST_STATE_READY) , I see:

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:516 Seeking to offset 0 using fseeko
19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:416 opened file C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4, seekable 1

6.3 seconds after I call gst_element_set_state(gstPipeline, GST_STATE_PAUSED) , I see:

19-03-25T20:44:25.853308 DEBUG filesink gstfilesink.c:586 Ignored SEGMENT event of format 3 (time)

My best guess is that it's some kind of rare timing bug within gstreamer (which most pipelines are lucky to avoid).

I am looking for tips about how to diagnose the exact cause of this bug: But keep in mind that I have no debug symbols because I'm on Windows.

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

all_paused_except_sink_0.svg (190K) Download Attachment

Thornton, Keith

AW: Trying to diagnose a READY --> PAUSED transition bug

Hi,

Can filesink accept a segment in time format, I would have thought in needs a byte format segment message

Von: gstreamer-devel <[hidden email]> Im Auftrag von David Ing
Gesendet: Montag, 25. März 2019 22:20
An: Discussion of the development of and with GStreamer <[hidden email]>
Betreff: Trying to diagnose a READY --> PAUSED transition bug

Also:

The issue does not repro on Linux (only Windows).
I use the same basic code to render many other kinds of jobs and I never have a problem with the GstFileSink. It is only for this one specific pipeline that I have the problem.
I am 100% certain that this isn't some kind of file system issue (e.g. folder permissions).

For logging I set the the "filesink" category to TRACE and this is the entirety of what it shows me:

Pipeline is in NULL state, as I connect the muxer to the filesink I see this:

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:294 filename : C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:295 uri : file:///C:/dev/github/panopto/panopto-core/Debug/x64/test-scratch/2019-03-25T20-44-11.942351/CompositionTests/Debug/0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

Immediately after I call gst_element_set_state(gstPipeline, GST_STATE_READY) , I see:

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:516 Seeking to offset 0 using fseeko

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:416 opened file C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4, seekable 1

6.3 seconds after I call gst_element_set_state(gstPipeline, GST_STATE_PAUSED) , I see:

19-03-25T20:44:25.853308 DEBUG filesink gstfilesink.c:586 Ignored SEGMENT event of format 3 (time)

My best guess is that it's some kind of rare timing bug within gstreamer (which most pipelines are lucky to avoid).

I am looking for tips about how to diagnose the exact cause of this bug: But keep in mind that I have no debug symbols because I'm on Windows.

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

Thibault Saunier-4

Re: Trying to diagnose a READY --> PAUSED transition bug

Hey,

Looking at the diagram, it looks like the muxer is never outputing any buffer and is not negotiating its output, you should check how buffer are flowing in the debug log, also a stack trace could be useful.

BR,

Thibault

On Tue, Mar 26, 2019 at 8:08 AM Thornton, Keith <[hidden email]> wrote:

Hi,

Can filesink accept a segment in time format, I would have thought in needs a byte format segment message

Von: gstreamer-devel <[hidden email]> Im Auftrag von David Ing
Gesendet: Montag, 25. März 2019 22:20
An: Discussion of the development of and with GStreamer <[hidden email]>
Betreff: Trying to diagnose a READY --> PAUSED transition bug

I am using Gstreamer 1.14.4. I am having an issue with one of my pipelines on Windows. I attached an SVG file which shows my pipeline at the point in time when it gets stuck. The issue occurs when I try to move my pipeline from READY to PAUSED. I do this by calling gst_element_set_state(gstPipeline, GST_STATE_PAUSED), and after that call is made, I see all elements within the pipeline transition to PAUSED except the GstFileSink which remains stuck in READY.

Also:

The issue does not repro on Linux (only Windows).
I use the same basic code to render many other kinds of jobs and I never have a problem with the GstFileSink. It is only for this one specific pipeline that I have the problem.
I am 100% certain that this isn't some kind of file system issue (e.g. folder permissions).

For logging I set the the "filesink" category to TRACE and this is the entirety of what it shows me:

Pipeline is in NULL state, as I connect the muxer to the filesink I see this:

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:294 filename : C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:295 uri : file:///C:/dev/github/panopto/panopto-core/Debug/x64/test-scratch/2019-03-25T20-44-11.942351/CompositionTests/Debug/0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

Immediately after I call gst_element_set_state(gstPipeline, GST_STATE_READY) , I see:

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:516 Seeking to offset 0 using fseeko

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:416 opened file C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4, seekable 1

6.3 seconds after I call gst_element_set_state(gstPipeline, GST_STATE_PAUSED) , I see:

19-03-25T20:44:25.853308 DEBUG filesink gstfilesink.c:586 Ignored SEGMENT event of format 3 (time)

My best guess is that it's some kind of rare timing bug within gstreamer (which most pipelines are lucky to avoid).

I am looking for tips about how to diagnose the exact cause of this bug: But keep in mind that I have no debug symbols because I'm on Windows.

_______________________________________________
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

Nicolas Dufresne-5

Re: Trying to diagnose a READY --> PAUSED transition bug

In reply to this post by David Ing

Le lun. 25 mars 2019 17 h 26, David Ing <[hidden email]> a écrit :

I am using Gstreamer 1.14.4. I am having an issue with one of my pipelines on Windows. I attached an SVG file which shows my pipeline at the point in time when it gets stuck. The issue occurs when I try to move my pipeline from READY to PAUSED. I do this by calling gst_element_set_state(gstPipeline, GST_STATE_PAUSED), and after that call is made, I see all elements within the pipeline transition to PAUSED except the GstFileSink which remains stuck in READY.

Also:
The issue does not repro on Linux (only Windows).
I use the same basic code to render many other kinds of jobs and I never have a problem with the GstFileSink. It is only for this one specific pipeline that I have the problem.
I am 100% certain that this isn't some kind of file system issue (e.g. folder permissions).
For logging I set the the "filesink" category to TRACE and this is the entirety of what it shows me:

Pipeline is in NULL state, as I connect the muxer to the filesink I see this:

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:294 filename : C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4
19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:295 uri : file:///C:/dev/github/panopto/panopto-core/Debug/x64/test-scratch/2019-03-25T20-44-11.942351/CompositionTests/Debug/0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

Immediately after I call gst_element_set_state(gstPipeline, GST_STATE_READY) , I see:

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:516 Seeking to offset 0 using fseeko
19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:416 opened file C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4, seekable 1

6.3 seconds after I call gst_element_set_state(gstPipeline, GST_STATE_PAUSED) , I see:

19-03-25T20:44:25.853308 DEBUG filesink gstfilesink.c:586 Ignored SEGMENT event of format 3 (time)

My best guess is that it's some kind of rare timing bug within gstreamer (which most pipelines are lucky to avoid).

I am looking for tips about how to diagnose the exact cause of this bug: But keep in mind that I have no debug symbols because I'm on Windows.

Windows build have debug symbols, but only gdb format. You can download gdb for Windows in order to trace. Best experience is if you have made your own build, since then it will be able to map to the source code. Another note, there has been load of work done to support a subset of the build, using msvc, that is currently in GStreamer master of cerbero as a variant (-v msvc iirc)

_______________________________________________
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

David Ing

Re: Trying to diagnose a READY --> PAUSED transition bug

Keith -- I'm afraid I don't know anything about segments, but the log does say that the filesink ignored the message. So I am guessing that it isn't the problem, but I will investigate that further.

Thibault -- It does look like there was an issue with caps negotiation (from the diagram). I will definitely investigate that further.

Nicolas -- An excellent suggestion. I may need to go down that road.

Also: I just learned that when I use a different muxer (qtmux) and encoder (voaacenc), the pipeline does enter the PLAYING state ... but the job takes a very long time (2:53) to create the audio composition (only 1:16 of audio content).

I will keep investigating. Thanks for all your suggestions so far.

On Tue, Mar 26, 2019 at 6:20 AM Nicolas Dufresne <[hidden email]> wrote:

Le lun. 25 mars 2019 17 h 26, David Ing <[hidden email]> a écrit :
I am using Gstreamer 1.14.4. I am having an issue with one of my pipelines on Windows. I attached an SVG file which shows my pipeline at the point in time when it gets stuck. The issue occurs when I try to move my pipeline from READY to PAUSED. I do this by calling gst_element_set_state(gstPipeline, GST_STATE_PAUSED), and after that call is made, I see all elements within the pipeline transition to PAUSED except the GstFileSink which remains stuck in READY.

Also:
The issue does not repro on Linux (only Windows).
I use the same basic code to render many other kinds of jobs and I never have a problem with the GstFileSink. It is only for this one specific pipeline that I have the problem.
I am 100% certain that this isn't some kind of file system issue (e.g. folder permissions).
For logging I set the the "filesink" category to TRACE and this is the entirety of what it shows me:

Pipeline is in NULL state, as I connect the muxer to the filesink I see this:

19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:294 filename : C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4
19-03-25T20:44:19.420327 INFO filesink gstfilesink.c:295 uri : file:///C:/dev/github/panopto/panopto-core/Debug/x64/test-scratch/2019-03-25T20-44-11.942351/CompositionTests/Debug/0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4

Immediately after I call gst_element_set_state(gstPipeline, GST_STATE_READY) , I see:

19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:516 Seeking to offset 0 using fseeko
19-03-25T20:44:19.458327 DEBUG filesink gstfilesink.c:416 opened file C:\dev\github\panopto\panopto-core\Debug\x64\test-scratch\2019-03-25T20-44-11.942351\CompositionTests\Debug\0ed40ba8-7d3d-4569-8294-aa02017efdfc-9531e8a6-d94f-44ed-a79a-aa0b0008a713.mp4, seekable 1

6.3 seconds after I call gst_element_set_state(gstPipeline, GST_STATE_PAUSED) , I see:

19-03-25T20:44:25.853308 DEBUG filesink gstfilesink.c:586 Ignored SEGMENT event of format 3 (time)

My best guess is that it's some kind of rare timing bug within gstreamer (which most pipelines are lucky to avoid).

I am looking for tips about how to diagnose the exact cause of this bug: But keep in mind that I have no debug symbols because I'm on Windows.

Windows build have debug symbols, but only gdb format. You can download gdb for Windows in order to trace. Best experience is if you have made your own build, since then it will be able to map to the source code. Another note, there has been load of work done to support a subset of the build, using msvc, that is currently in GStreamer master of cerbero as a variant (-v msvc iirc)

_______________________________________________
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

Tim Müller

Re: Trying to diagnose a READY --> PAUSED transition bug

In reply to this post by Nicolas Dufresne-5

On Tue, 2019-03-26 at 09:19 -0400, Nicolas Dufresne wrote:

> Windows build have debug symbols, but only gdb format. You can
> download gdb for Windows in order to trace. Best experience is if you
> have made your own build, since then it will be able to map to the
> source code. Another note, there has been load of work done to
> support a subset of the build, using msvc, that is currently in
> GStreamer master of cerbero as a variant (-v msvc iirc)

There are experimental MSVC binaries available for 1.15.2 in case you
want to give those a spin.

https://gstreamer.freedesktop.org/pkg/windows/1.15.2/

Cheers
Tim

--
Tim Müller, Centricular Ltd - http://www.centricular.com

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