gst_pipeline_set_clock() doesn't take effect

[Halley Zhao]

Hi Expert:

  I created my customized pipeline as "appsrc-->h264parse-->v4l2h264dec-->waylandsink".

  then I try to use my customized clock to control the video playback (in fact, I used the above pipeline inside a bigger/complete pipeline). however, I found gst_pipeline_set_clock() doens't work for me.

  

  I call gst_pipeline_set_clock() before setting the pipeline to PLAYING state, and gst logs shows it take effect (the clock is set to each element); but when the pipeline changed state to PAUSED, gst_bin_provide_clock_func() return NULL (it is strange), and gst_system_clock_obtain() is called to update the clock.

  I'm not sure whether there is something wrong in my code, or potential mistake in gst base code.

here is my sample code and gst logs(GST_DEBUG=*:6).

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

[Halley Zhao]

Hi Expert:

  I created my customized pipeline as "appsrc-->h264parse-->v4l2h264dec-->waylandsink".

  then I try to use my customized clock to control the video playback (in fact, I used the above pipeline inside a bigger/complete pipeline). however, I found gst_pipeline_set_clock() doens't work for me.

  

  I call gst_pipeline_set_clock() before setting the pipeline to PLAYING state, and gst logs shows it take effect (the clock is set to each element); but when the pipeline changed state to PAUSED, gst_bin_provide_clock_func() return NULL (it is strange), and gst_system_clock_obtain() is called to update the clock.

  I'm not sure whether there is something wrong in my code, or potential mistake in gst base code.

here is my sample code and gst logs(GST_DEBUG=*:6).

I filtered the log with 'clock' as key word as attachment since it is big.

the piece log with context is as following:

17526 0:00:00.750638375  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:839:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 calling dispatch with state-changed message: 0xffff9c003400, time 99:99:99.999999999, seq-num 43, element 'my_pipeline',                    GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_PLAYING;

17527 (bus_call, 87)my_pipeline state change, old state: READY, new state: PAUSED

17528 0:00:00.750744875  8744     0x3d233770 DEBUG                GST_BUS gstbus.c:360:gst_bus_post:<bus1> [msg 0xffff9c003380] pushed on async queue

17529 0:00:00.750781500  8744 0xffffa4002580 LOG              GST_MESSAGE gstmessage.c:208:_gst_message_free: finalize message 0xffff9c003400, state-changed from my_pipeline

17530 0:00:00.750810750  8744     0x3d233770 DEBUG                    bin gstbin.c:3484:bin_handle_async_done:<my_pipeline> all async-done, starting state continue

17531 0:00:00.750875750  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:844:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 handler returns 1

17532 0:00:00.750890750  8744     0x3d233770 DEBUG                    bin gstbin.c:3289:bin_push_state_continue:<my_pipeline> pushing continue on thread pool

17533 0:00:00.750950875  8744 0xffffa4002580 LOG                  GST_BUS gstbus.c:522:gst_bus_timed_pop_filtered:<bus1> have 1 messages

17534 0:00:00.750982000  8744 0xffffa4002580 LOG                 GST_POLL gstpoll.c:314:release_wakeup: 0x3d154a30: release

17535 0:00:00.751025375  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:546:gst_bus_timed_pop_filtered:<bus1> got message 0xffff9c003380, async-done from my_pipeline, type mask is 4294967295

17536 0:00:00.751072625  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:839:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 calling dispatch with async-done message: 0xffff9c003380, time 99:99:99.999999999, seq-num 42, element 'my_pipeline',                       GstMessageAsyncDone, running-time=(guint64)18446744073709551615;

17537 0:00:00.751152000  8744 0xffffa4002580 LOG              GST_MESSAGE gstmessage.c:208:_gst_message_free: finalize message 0xffff9c003380, async-done from my_pipeline

17538 0:00:00.751184000  8744     0x3d233770 DEBUG                GST_BUS gstbus.c:353:gst_bus_post:<bus0> [msg 0xffff9c003300] dropped

17539 0:00:00.751197000  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:844:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 handler returns 1

17540 0:00:00.751258000  8744     0x3d233770 DEBUG               basesink gstbasesink.c:2265:gst_base_sink_wait_preroll:<my_sink> waiting in preroll for flush or PLAYING

17541 0:00:00.751328500  8744 0xffff9c007680 DEBUG                    bin gstbin.c:3224:gst_bin_continue_func:<my_pipeline> waiting for state lock

17542 0:00:00.751413500  8744 0xffff9c007680 DEBUG                    bin gstbin.c:3227:gst_bin_continue_func:<my_pipeline> doing state continue

17543 0:00:00.751454875  8744 0xffff9c007680 INFO              GST_STATES gstbin.c:3248:gst_bin_continue_func:<my_pipeline> continue state change PAUSED to PLAYING, final PLAYING

17544 0:00:00.751511250  8744 0xffff9c007680 DEBUG               pipeline gstpipeline.c:412:gst_pipeline_change_state:<my_pipeline> selecting clock and base_time

17545 0:00:00.751552375  8744 0xffff9c007680 DEBUG               pipeline gstpipeline.c:433:gst_pipeline_change_state:<my_pipeline> Need to update start_time

17546 0:00:00.751589625  8744 0xffff9c007680 DEBUG               pipeline gstpipeline.c:438:gst_pipeline_change_state:<my_pipeline> Need to update clock.

17547 0:00:00.751628875  8744 0xffff9c007680 DEBUG                    bin gstbin.c:837:gst_bin_provide_clock_func:<my_pipeline> returning old clock (nil)

17548 0:00:00.751669875  8744 0xffff9c007680 DEBUG              GST_CLOCK gstsystemclock.c:353:gst_system_clock_obtain: creating new static system clock

17549 0:00:00.751782500  8744 0xffff9c007680 DEBUG               GST_POLL gstpoll.c:681:gst_poll_new: 0xffffa0003c00: new controllable : 1

17550 0:00:00.751897750  8744 0xffff9c007680 DEBUG               GST_POLL gstpoll.c:848:gst_poll_add_fd_unlocked: 0xffffa0003c00: fd (fd:120, idx:0)

17551 0:00:00.751948625  8744 0xffff9c007680 DEBUG               GST_POLL gstpoll.c:1015:gst_poll_fd_ctl_read_unlocked: 0xffffa0003c00: fd (fd:120, idx:0), active : 1

17552 0:00:00.752028625  8744 0xffff9c007680 DEBUG              GST_CLOCK gstpipeline.c:732:gst_pipeline_provide_clock_func: pipeline obtained system clock: 0xffffa0002160 (GstSystemClock)

17553 0:00:00.752084500  8744 0xffff9c007680 DEBUG              GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock> internal time 0:15:45.099030375

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

[Halley Zhao]

since the previous log shows gst bin/pipeline reset clock to GstSystemClock after I called gst_pipeline_set_clock(),

I tried to call gst_pipeline_set_clock() after pipeline reach PLAYING state.

then the clock seems take effect, (my func to generate clock time is called); but playback stuck after several frame.

seems time mismatch between element base_time and new clock time

18283 0:00:01.159746000 26457 0xffffa80060f0 DEBUG               basesink gstbasesink.c:2603:gst_base_sink_do_sync:<my_sink> possibly waiting for clock to reach 0:00:01.000000000, adjusted 0:00:01.           000000000

18284 0:00:01.159788500 26457     0x203b60a0 LOG                  adapter gstadapter.c:974:gst_adapter_get_buffer:<GstAdapter@0x203a3000> getting buffer of 950 bytes

18285 0:00:01.159843250 26457 0xffffa80060f0 LOG                 basesink gstbasesink.c:2177:gst_base_sink_wait_clock:<my_sink> time 0:00:01.000000000, base_time 1:51:09.499730750

Halley Zhao <[hidden email]> 于2019年5月20日周一 上午10:23写道：

Hi Expert:

  I created my customized pipeline as "appsrc-->h264parse-->v4l2h264dec-->waylandsink".

  then I try to use my customized clock to control the video playback (in fact, I used the above pipeline inside a bigger/complete pipeline). however, I found gst_pipeline_set_clock() doens't work for me.

  

  I call gst_pipeline_set_clock() before setting the pipeline to PLAYING state, and gst logs shows it take effect (the clock is set to each element); but when the pipeline changed state to PAUSED, gst_bin_provide_clock_func() return NULL (it is strange), and gst_system_clock_obtain() is called to update the clock.

  I'm not sure whether there is something wrong in my code, or potential mistake in gst base code.

here is my sample code and gst logs(GST_DEBUG=*:6).

I filtered the log with 'clock' as key word as attachment since it is big.

the piece log with context is as following:

17526 0:00:00.750638375  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:839:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 calling dispatch with state-changed message: 0xffff9c003400, time 99:99:99.999999999, seq-num 43, element 'my_pipeline',                    GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_PLAYING;

17527 (bus_call, 87)my_pipeline state change, old state: READY, new state: PAUSED

17528 0:00:00.750744875  8744     0x3d233770 DEBUG                GST_BUS gstbus.c:360:gst_bus_post:<bus1> [msg 0xffff9c003380] pushed on async queue

17529 0:00:00.750781500  8744 0xffffa4002580 LOG              GST_MESSAGE gstmessage.c:208:_gst_message_free: finalize message 0xffff9c003400, state-changed from my_pipeline

17530 0:00:00.750810750  8744     0x3d233770 DEBUG                    bin gstbin.c:3484:bin_handle_async_done:<my_pipeline> all async-done, starting state continue

17531 0:00:00.750875750  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:844:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 handler returns 1

17532 0:00:00.750890750  8744     0x3d233770 DEBUG                    bin gstbin.c:3289:bin_push_state_continue:<my_pipeline> pushing continue on thread pool

17533 0:00:00.750950875  8744 0xffffa4002580 LOG                  GST_BUS gstbus.c:522:gst_bus_timed_pop_filtered:<bus1> have 1 messages

17534 0:00:00.750982000  8744 0xffffa4002580 LOG                 GST_POLL gstpoll.c:314:release_wakeup: 0x3d154a30: release

17535 0:00:00.751025375  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:546:gst_bus_timed_pop_filtered:<bus1> got message 0xffff9c003380, async-done from my_pipeline, type mask is 4294967295

17536 0:00:00.751072625  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:839:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 calling dispatch with async-done message: 0xffff9c003380, time 99:99:99.999999999, seq-num 42, element 'my_pipeline',                       GstMessageAsyncDone, running-time=(guint64)18446744073709551615;

17537 0:00:00.751152000  8744 0xffffa4002580 LOG              GST_MESSAGE gstmessage.c:208:_gst_message_free: finalize message 0xffff9c003380, async-done from my_pipeline

17538 0:00:00.751184000  8744     0x3d233770 DEBUG                GST_BUS gstbus.c:353:gst_bus_post:<bus0> [msg 0xffff9c003300] dropped

17539 0:00:00.751197000  8744 0xffffa4002580 DEBUG                GST_BUS gstbus.c:844:gst_bus_source_dispatch:<bus1> source 0x3d21dc00 handler returns 1

17540 0:00:00.751258000  8744     0x3d233770 DEBUG               basesink gstbasesink.c:2265:gst_base_sink_wait_preroll:<my_sink> waiting in preroll for flush or PLAYING

17541 0:00:00.751328500  8744 0xffff9c007680 DEBUG                    bin gstbin.c:3224:gst_bin_continue_func:<my_pipeline> waiting for state lock

17542 0:00:00.751413500  8744 0xffff9c007680 DEBUG                    bin gstbin.c:3227:gst_bin_continue_func:<my_pipeline> doing state continue

17543 0:00:00.751454875  8744 0xffff9c007680 INFO              GST_STATES gstbin.c:3248:gst_bin_continue_func:<my_pipeline> continue state change PAUSED to PLAYING, final PLAYING

17544 0:00:00.751511250  8744 0xffff9c007680 DEBUG               pipeline gstpipeline.c:412:gst_pipeline_change_state:<my_pipeline> selecting clock and base_time

17545 0:00:00.751552375  8744 0xffff9c007680 DEBUG               pipeline gstpipeline.c:433:gst_pipeline_change_state:<my_pipeline> Need to update start_time

17546 0:00:00.751589625  8744 0xffff9c007680 DEBUG               pipeline gstpipeline.c:438:gst_pipeline_change_state:<my_pipeline> Need to update clock.

17547 0:00:00.751628875  8744 0xffff9c007680 DEBUG                    bin gstbin.c:837:gst_bin_provide_clock_func:<my_pipeline> returning old clock (nil)

17548 0:00:00.751669875  8744 0xffff9c007680 DEBUG              GST_CLOCK gstsystemclock.c:353:gst_system_clock_obtain: creating new static system clock

17549 0:00:00.751782500  8744 0xffff9c007680 DEBUG               GST_POLL gstpoll.c:681:gst_poll_new: 0xffffa0003c00: new controllable : 1

17550 0:00:00.751897750  8744 0xffff9c007680 DEBUG               GST_POLL gstpoll.c:848:gst_poll_add_fd_unlocked: 0xffffa0003c00: fd (fd:120, idx:0)

17551 0:00:00.751948625  8744 0xffff9c007680 DEBUG               GST_POLL gstpoll.c:1015:gst_poll_fd_ctl_read_unlocked: 0xffffa0003c00: fd (fd:120, idx:0), active : 1

17552 0:00:00.752028625  8744 0xffff9c007680 DEBUG              GST_CLOCK gstpipeline.c:732:gst_pipeline_provide_clock_func: pipeline obtained system clock: 0xffffa0002160 (GstSystemClock)

17553 0:00:00.752084500  8744 0xffff9c007680 DEBUG              GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock> internal time 0:15:45.099030375

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

[Tim Müller]

On Mon, 2019-05-20 at 10:17 +0800, Halley Zhao wrote:

Hi,

>   then I try to use my customized clock to control the video playback
> (in fact, I used the above pipeline inside a bigger/complete
> pipeline). however, I found gst_pipeline_set_clock() doesn't work for
> me.
>  
>   I call gst_pipeline_set_clock() before setting the pipeline to
> PLAYING state, and gst logs shows it take effect (the clock is set to
> each element); but when the pipeline changed state to
> PAUSED, gst_bin_provide_clock_func() return NULL (it is strange),
> and gst_system_clock_obtain() is called to update the clock.

Have you tried gst_pipeline_use_clock() yet?

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

[Halley Zhao]

thanks sir. it works!

Tim Müller <[hidden email]> 于2019年5月20日周一 下午2:40写道：

On Mon, 2019-05-20 at 10:17 +0800, Halley Zhao wrote:

Hi,

>   then I try to use my customized clock to control the video playback
> (in fact, I used the above pipeline inside a bigger/complete
> pipeline). however, I found gst_pipeline_set_clock() doesn't work for
> me.
>   
>   I call gst_pipeline_set_clock() before setting the pipeline to
> PLAYING state, and gst logs shows it take effect (the clock is set to
> each element); but when the pipeline changed state to
> PAUSED, gst_bin_provide_clock_func() return NULL (it is strange),
> and gst_system_clock_obtain() is called to update the clock.

Have you tried gst_pipeline_use_clock() yet?

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

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

[Nicolas Dufresne-5]

Le lun. 20 mai 2019 00 h 26, Halley Zhao <[hidden email]> a écrit :

Hi Expert:

  I created my customized pipeline as "appsrc-->h264parse-->v4l2h264dec-->waylandsink".

  then I try to use my customized clock to control the video playback (in fact, I used the above pipeline inside a bigger/complete pipeline). however, I found gst_pipeline_set_clock() doens't work for me.

set_clock is a one time thing, use gst_pipeline_use_clock() instead.

  

  I call gst_pipeline_set_clock() before setting the pipeline to PLAYING state, and gst logs shows it take effect (the clock is set to each element); but when the pipeline changed state to PAUSED, gst_bin_provide_clock_func() return NULL (it is strange), and gst_system_clock_obtain() is called to update the clock.

  I'm not sure whether there is something wrong in my code, or potential mistake in gst base code.

here is my sample code and gst logs(GST_DEBUG=*:6).

_______________________________________________
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