After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 757322 - ref/unref inconsistency in glvideomixer bin causing crash
ref/unref inconsistency in glvideomixer bin causing crash
Status: RESOLVED INCOMPLETE
Product: GStreamer
Classification: Platform
Component: gst-plugins-bad
1.6.0
Other Linux
: Normal normal
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2015-10-29 16:02 UTC by Topolsky
Modified: 2018-02-09 01:12 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
run with ./playout -t test.mp4 test2.mp4 test3.mp4 (47.53 KB, text/x-csrc)
2015-10-29 16:02 UTC, Topolsky
Details

Description Topolsky 2015-10-29 16:02:41 UTC
Created attachment 314415 [details]
run with ./playout -t test.mp4 test2.mp4 test3.mp4

I extended playout example in gst-plugins-bad/tests/examples/playout.c with ability to loop the playlist, and altered the pipeline to add tee and appsink(which are causing bug sooner). However this is not about the example but rather about bug in glvideomixer bin or somewhere else which may cause problems in its applications.

After many times of switches the playout example shows critical warnings of type:

0:28:28.994682124  9725 0x7fff54074690 DEBUG                playout playout.c:911:playout_item_no_more_pads: v/run2s_08.mp4: prepared
0:28:29.007058053  9725 0x7fff54a9a590 DEBUG                playout playout.c:599:playout_item_pad_probe_video_pad_eos_on_buffer: v/run2s_07.mp4: first vbuffer -> aggregating
0:28:29.011223748  9725 0x7fff541b12a0 WARN              aggregator gstaggregator.c:1368:gst_aggregator_query_latency_unlocked:<mixer> Latency query failed
0:28:29.011312251  9725 0x7fff541b12a0 WARN                     bin gstbin.c:2524:gst_bin_do_latency_func:<autovideosink0> did not really configure latency of 0:00:00.000000000

(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element glcolorconvertelement891, but it is in PLAYING instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.

with backtrace(catched with G_DEBUG=fatal-warnings):

>~"#0  0x00007ffff6cadc13 in g_logv () from /lib/x86_64-linux-gnu/libglib-2.0.so.0\n"
>~"#1  0x00007ffff6cadd72 in g_log () from /lib/x86_64-linux-gnu/libglib-2.0.so.0\n"
>~"#2  0x00007ffff6f7ad2c in g_object_unref () from /usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0\n"
>~"#3  0x00007ffff6f9ad8c in g_value_reset () from /usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0\n"
>~"#4  0x00007ffff7af6e08 in gst_bin_change_state_func (element=0x82d160, transition=36) at gstbin.c:2752\n"
>~"#5  0x00007ffff4aa21fd in gst_gl_mixer_bin_change_state (element=0x82d160, transition=36) at gstglmixerbin.c:511\n"
>~"#6  0x00007ffff7b16d32 in gst_element_change_state (element=element@entry=0x82d160, transition=transition@entry=36) at gstelement.c:2604\n"
>~"#7  0x00007ffff7b1740c in gst_element_set_state_func (element=0x82d160, state=GST_STATE_PLAYING) at gstelement.c:2560\n"
>~"#8  0x00007ffff7af71d9 in gst_bin_element_set_state (next=GST_STATE_PLAYING, current=GST_STATE_PAUSED, start_time=0, base_time=0, element=0x82d160, bin=0x814120) at gstbin.c:2341\n"
>~"#9  gst_bin_change_state_func (element=0x814120, transition=GST_STATE_CHANGE_PAUSED_TO_PLAYING) at gstbin.c:2694\n"
>~"#10 0x00007ffff7b16d32 in gst_element_change_state (element=element@entry=0x814120, transition=transition@entry=GST_STATE_CHANGE_PAUSED_TO_PLAYING) at gstelement.c:2604\n"
>~"#11 0x00007ffff7af0539 in gst_bin_continue_func (data=0x7fff8c002510) at gstbin.c:3001\n"
>~"#12 0x00007ffff6ccc88c in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0\n"
>~"#13 0x00007ffff6ccbf05 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0\n"
>~"#14 0x00007ffff5d6d182 in start_thread (arg=0x7fff4bfff700) at pthread_create.c:312\n"
>~"#15 0x00007ffff699347d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111\n" 

First occurence of such warning can be triggered after few minutes, but in some cases(different HW) maybe later.
 
It seems that the element is unrefed by something and thus being freed, although there is no unref of any element in example code itself (in original playout there was one unref of mixer, but I removed it, by using the pointer to the element directly as the mixer shall never by changed during playout execution).

After some more time of playback the playout crashes with these critical warnings and then SIGABRT or SIGSEGV, usualy the memory accessed is already zeroed:

0:28:32.931723569  9725 0x7fff5507e120 WARN                 basesrc gstbasesrc.c:3481:gst_base_src_start_complete:<source> pad not activated yet
0:28:32.931961332  9725 0x7fff5507e120 WARN                 basesrc gstbasesrc.c:3481:gst_base_src_start_complete:<source> pad not activated yet

(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element queue1783, but it is in PAUSED instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.


(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element capsfilter1783, but it is in PAUSED instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.


(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element audioconvert891, but it is in PAUSED instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.


(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element audioresample891, but it is in PAUSED instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.


(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element queue1782, but it is in PAUSED instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.


(cplayout:9725): GStreamer-CRITICAL **: 
Trying to dispose element bin891, but it is in READY instead of the NULL state.
You need to explicitly set elements to the NULL state before
dropping the final reference, to allow them to clean up.
This problem may also be caused by a refcounting bug in the
application or some element.

0:28:32.932629662  9725 0x7fff553bdbc0 WARN                 qtdemux qtdemux_types.c:221:qtdemux_type_get: unknown QuickTime node type iods
0:28:32.932700452  9725 0x7fff553bdbc0 WARN                 basesrc gstbasesrc.c:2391:gst_base_src_update_length:<source> processing at or past EOS
0:28:32.964388487  9725 0x7fff54240ab0 DEBUG                playout playout.c:770:playout_item_new_pad: v/run2s_08.mp4: new pad: 0x7fff54c5f940, caps: video/x-raw

(cplayout:9725): GStreamer-CRITICAL **: gst_bin_add: assertion 'GST_IS_BIN (bin)' failed
0:28:32.964494435  9725 0x7fff54240ab0 INFO                 playout playout.c:866:playout_item_new_pad: v/run2s_08.mp4: unable to sync video queue state with decoder
0:28:32.964560930  9725 0x7fff54240ab0 DEBUG                playout playout.c:770:playout_item_new_pad: v/run2s_08.mp4: new pad: 0x7fff55a0b0c0, caps: audio/x-raw
0:28:32.964582296  9725 0x7fff54240ab0 DEBUG                playout playout.c:794:playout_item_new_pad: v/run2s_08.mp4: converting audio caps

(cplayout:9725): GStreamer-CRITICAL **: gst_bin_add_many: assertion 'GST_IS_BIN (bin)' failed
0:28:32.965070949  9725 0x7fff54240ab0 INFO                 playout playout.c:818:playout_item_new_pad: v/run2s_08.mp4: unable to sync audio converter state with decoder
0:28:32.965085309  9725 0x7fff54240ab0 DEBUG                playout playout.c:911:playout_item_no_more_pads: v/run2s_08.mp4: prepared
*** Error in `/home/topolsky/Documents/Playout/vliaskovs-playout-16/compositor_prototype/c-prototype/cplayout': malloc(): smallbin double linked list corrupted: 0x00007fff44568f00 ***


-----------


Additional infos:
Bug is triggered on
Ubuntu 14.04
Archlinux

i5, i7 CPU with integrated GPU (bug triggered on 3 different PCs)

Commits of 1.6 used(same on all PCs):

gst-libav  ~~ 48e0e053bdb16976c6d18f4d2a982e8139538245
gst-plugins-bad  ~~ 664e0fb331ce18751ebe96b129fd125d4ae0a69c
gst-plugins-base  ~~ 7037f25bba7aebfa16dced3a115952ef2b444b10
gst-plugins-good  ~~ c5110bb839d98a82d87f68071f44669df3f9e3f4
gst-plugins-ugly  ~~ b200d017f92c7f5371d3a2777b7bbaae85ced6b7
gstreamer  ~~ 05239c58e3223de9e97ab575e027d6e1735b85fc

Compilation (of attached example):
gcc playout-min.c -g `pkg-config --cflags --libs gstreamer-1.0 gstreamer-app-1.0 gstreamer-video-1.0`  -o playout

Steps to reproduce:
Need to have some videos of 2 seconds length to trigger the bug sooner.

run with -t switch 

./playout -t video01.mp4 -t video02.mp4 -t video03.mp4 -t video04.mp4

The segfault usualy occures after 40mins, but the critical warning which is the cause happens after few minutes.
Comment 1 Matthew Waters (ystreet00) 2016-11-15 07:23:20 UTC
This example is not valgrind clean.  Please fix any errors reported by valgrind before we can look into this.
Comment 2 Vincent Penquerc'h 2017-04-11 15:45:15 UTC
      g_timeout_add (500, (GSourceFunc) playout_remove_pad, &removePadArg);

This keeps a pointer to the stack, which will be unwound. playout_remove_pad will access stale memory. Also the objects in that structure aren't given refs to survive the delay.

That's not the main problem though, that's still being elusive.
Comment 3 Matthew Waters (ystreet00) 2018-02-09 01:12:53 UTC
Closing this bug report as no further information has been provided. Please feel free to reopen this bug report if you can provide the information that was asked for in a previous comment.
Thanks!