[Bug 731121] New: Race condition causes alsasink to use invalid caps when a pipeline fails to start
GStreamer (bugzilla.gnome.org)
bugzilla at gnome.org
Mon Jun 2 11:10:30 PDT 2014
https://bugzilla.gnome.org/show_bug.cgi?id=731121
GStreamer | gst-plugins-base | git
Summary: Race condition causes alsasink to use invalid caps
when a pipeline fails to start
Classification: Platform
Product: GStreamer
Version: git
OS/Version: Linux
Status: NEW
Severity: normal
Priority: Normal
Component: gst-plugins-base
AssignedTo: gstreamer-bugs at lists.freedesktop.org
ReportedBy: vincent.penquerch at collabora.co.uk
QAContact: gstreamer-bugs at lists.freedesktop.org
GNOME version: ---
Writing out my findings to remember, I will continue debugging this tomorrow if
not preempted.
It started as a simple one off assert in gst_value_intersect:
(gst-launch-1.0:4831): GStreamer-CRITICAL **: gst_value_intersect: assertion
'G_IS_VALUE (value1)' failed
The pipeline normally does not assert, but errors out:
$ rm core ; while ! test -f core; do GST_DEBUG_FILE=gst.log
GST_DEBUG=5,*alsa*:9,*CAPS*:9 G_DEBUG=fatal_warnings gst-launch-1.0 filesrc
location=/home/v/Samples/8.wav ! wavparse ! audioconvert ! audioresample !
queue name=q48 filesrc location=/home/v/Samples/6.wav ! wavparse !
audioconvert ! audioresample ! queue name=q44 adder name=mix ! queue !
audioconvert ! alsasink q44. ! mix. q48. ! mix. ; done
Normal output:
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
ERROR: from element /GstPipeline:pipeline0/GstWavParse:wavparse0: Internal data
flow error.
Additional debug info:
gstwavparse.c(2168): gst_wavparse_loop ():
/GstPipeline:pipeline0/GstWavParse:wavparse0:
streaming task paused, reason not-negotiated (-4)
ERROR: pipeline doesn't want to preroll.
Setting pipeline to NULL ...
Freeing pipeline ...
It turns out there is a race condition somewhere which causes alsasink to use a
caps in _query_caps which it also deletes in _close.
One thread is the wavparse loop pushing:
#0 _g_log_abort (breakpoint=1) at gmessages.c:311
#1 0x00007f6b1b6986e4 in g_logv (log_domain=0x7f6b1bc862bc "GStreamer",
log_level=G_LOG_LEVEL_CRITICAL,
format=<optimised out>, args=<optimised out>) at gmessages.c:1033
#2 0x00007f6b1b698852 in g_log (log_domain=<optimised out>,
log_level=<optimised out>,
format=<optimised out>) at gmessages.c:1071
#3 0x00007f6b1bc76de4 in gst_value_intersect (dest=0x7f6b0f7fc170,
value1=0x7f6b0004a968,
value2=<optimised out>) at gstvalue.c:4752
#4 0x00007f6b1bc76c1d in gst_value_intersect_list (dest=0x7f6b0f7fc1f0,
value2=0x7f6afc0292a8,
value1=<optimised out>) at gstvalue.c:3642
#5 0x00007f6b1bc76c1d in gst_value_intersect_list (dest=0x7f6b0f7fc270,
value2=0x7f6b0004b5f8,
value1=<optimised out>) at gstvalue.c:3642
#6 0x00007f6b1bc56ef3 in gst_structure_intersect_field1 (id=52,
val1=0x7f6afc028238,
data=0x7f6b0f7fc2e0) at gststructure.c:3152
#7 0x00007f6b1bc57451 in gst_structure_foreach (structure=0x7f6afc00f060,
func=0x7f6b1bc56ea0 <gst_structure_intersect_field1>,
user_data=0x7f6b0f7fc2e0)
at gststructure.c:1126
#8 0x00007f6b1bc5a240 in gst_structure_intersect (struct1=0x7f6afc00f060,
struct2=0x7f6b0000d980)
at gststructure.c:3198
#9 0x00007f6b1bc0a83c in gst_caps_intersect_first (caps2=0x7f6b000032d0,
caps1=0x1a2e630)
at gstcaps.c:1620
#10 gst_caps_intersect_full (caps1=0x1a2e630, caps2=0x7f6b000032d0,
mode=<optimised out>)
at gstcaps.c:1659
#11 0x00007f6b182485b4 in gst_alsasink_getcaps (bsink=<optimised out>,
filter=0x1a2e630)
at gstalsasink.c:292
#12 0x00007f6b199ec098 in gst_base_sink_query_caps (bsink=0x1ad9440,
pad=<optimised out>,
filter=0x1a2e630) at gstbasesink.c:580
#13 0x00007f6b199ec221 in gst_base_sink_default_query (basesink=0x1ad9440,
query=0x1a2e050)
---Type <return> to continue, or q <return> to quit---
at gstbasesink.c:4813
#14 0x00007f6b1938ca55 in gst_audio_base_sink_query_pad (bsink=0x1ad9440,
query=0x1a2e050)
at gstaudiobasesink.c:411
#15 0x00007f6b18248465 in gst_alsasink_query (query=0x1a2e050, sink=0x1ad9440)
at gstalsasink.c:404
#16 gst_alsasink_query (sink=0x1ad9440, query=0x1a2e050) at gstalsasink.c:387
#17 0x00007f6b1bc38aa6 in gst_pad_query (pad=0x1ac13d0, query=0x1a2e050) at
gstpad.c:3575
#18 0x00007f6b1bc39099 in gst_pad_peer_query (pad=0x1ac11a0, query=0x1a2e050)
at gstpad.c:3706
#19 0x00007f6b1bc6c816 in gst_pad_peer_query_caps (pad=0x1ac11a0,
filter=0x1a2e630) at gstutils.c:2815
#20 0x00007f6b19a01287 in gst_base_transform_query_caps (filter=0x1ac4d90,
pad=0x1ac0f70,
trans=0x1aca240) at gstbasetransform.c:715
#21 gst_base_transform_default_query (trans=0x1aca240, direction=<optimised
out>, query=0x1a21f70)
at gstbasetransform.c:1535
#22 0x00007f6b1bc38aa6 in gst_pad_query (pad=0x1ac0f70, query=0x1a21f70) at
gstpad.c:3575
#23 0x00007f6b1bc39099 in gst_pad_peer_query (pad=0x1ac0d40, query=0x1a21f70)
at gstpad.c:3706
#24 0x00007f6b1bc67736 in query_caps_func (pad=0x1ac0d40, data=0x7f6b0f7fca30)
at gstutils.c:2485
#25 0x00007f6b1bc37cda in gst_pad_forward (pad=0x1ac0b10,
forward=0x7f6b1bc67710 <query_caps_func>,
user_data=0x7f6b0f7fca30) at gstpad.c:2787
#26 0x00007f6b1bc69c5a in gst_pad_proxy_query_caps (pad=0x1ac0b10,
query=0x1a21f70) at gstutils.c:2535
#27 0x00007f6b1bc3815d in gst_pad_query_caps_default (query=0x1a21f70,
pad=0x1ac0b10) at gstpad.c:2959
#28 gst_pad_query_default (pad=0x1ac0b10, parent=<optimised out>,
query=0x1a21f70) at gstpad.c:3070
#29 0x00007f6b1bc38aa6 in gst_pad_query (pad=0x1ac0b10, query=0x1a21f70) at
gstpad.c:3575
#30 0x00007f6b1bc39099 in gst_pad_peer_query (pad=0x1ac08e0, query=0x1a21f70)
at gstpad.c:3706
#31 0x00007f6b1bc6c816 in gst_pad_peer_query_caps (pad=0x1ac08e0,
filter=0x1ac4d90) at gstutils.c:2815
#32 0x00007f6b184574ac in gst_adder_sink_getcaps (filter=0x1ac4d90,
pad=0x1ae0060) at gstadder.c:249
#33 gst_adder_sink_query (query=0x1a2a770, pad=<optimised out>, pads=<optimised
out>,
user_data=<optimised out>) at gstadder.c:323
#34 gst_adder_sink_query (pads=<optimised out>, pad=<optimised out>,
query=0x1a2a770,
---Type <return> to continue, or q <return> to quit---
user_data=<optimised out>) at gstadder.c:312
#35 0x00007f6b19a09b15 in gst_collect_pads_query (pad=<optimised out>,
parent=<optimised out>,
query=0x1a2a770) at gstcollectpads.c:2091
#36 0x00007f6b1bc38aa6 in gst_pad_query (pad=0x1ae0060, query=0x1a2a770) at
gstpad.c:3575
#37 0x00007f6b1bc6a3d6 in gst_pad_query_caps (pad=0x1ae0060, filter=0x1ac4d90)
at gstutils.c:2769
#38 0x00007f6b1bc380e0 in gst_pad_query_accept_caps_default (query=0x1a2e140,
pad=0x1ae0060)
at gstpad.c:2922
#39 gst_pad_query_default (pad=0x1ae0060, parent=<optimised out>,
query=0x1a2e140) at gstpad.c:3066
#40 0x00007f6b19a0d907 in gst_collect_pads_query_default (pads=<optimised out>,
data=<optimised out>,
query=0x1a2e140, discard=<optimised out>) at gstcollectpads.c:2046
#41 0x00007f6b18457364 in gst_adder_sink_query (pads=<optimised out>,
pad=0x1adba00, query=0x1a2e140,
user_data=<optimised out>) at gstadder.c:330
#42 0x00007f6b19a09b15 in gst_collect_pads_query (pad=<optimised out>,
parent=<optimised out>,
query=0x1a2e140) at gstcollectpads.c:2091
#43 0x00007f6b1bc38aa6 in gst_pad_query (pad=0x1ae0060, query=0x1a2e140) at
gstpad.c:3575
#44 0x00007f6b1bc39099 in gst_pad_peer_query (pad=0x1ac06b0, query=0x1a2e140)
at gstpad.c:3706
#45 0x00007f6b1bc676f0 in query_accept_caps_func (pad=<optimised out>,
data=0x7f6b0f7fd2e0)
at gstutils.c:2425
#46 0x00007f6b1bc37cda in gst_pad_forward (pad=0x1ac0480,
forward=0x7f6b1bc676e0 <query_accept_caps_func>, user_data=0x7f6b0f7fd2e0)
at gstpad.c:2787
#47 0x00007f6b1bc69a71 in gst_pad_proxy_query_accept_caps (pad=0x1ac0480,
query=0x1a2e140)
at gstutils.c:2465
#48 0x00007f6b1bc3817d in gst_pad_query_accept_caps_default (query=0x1a2e140,
pad=0x1ac0480)
at gstpad.c:2913
#49 gst_pad_query_default (pad=0x1ac0480, parent=<optimised out>,
query=0x1a2e140) at gstpad.c:3066
#50 0x00007f6b1bc38aa6 in gst_pad_query (pad=0x1ac0480, query=0x1a2e140) at
gstpad.c:3575
#51 0x00007f6b1bc6c9e6 in gst_pad_query_accept_caps (pad=0x1ac0480,
caps=<optimised out>)
---Type <return> to continue, or q <return> to quit---
at gstutils.c:2852
#52 0x00007f6b1bc3192a in pre_eventfunc_check (event=0x7f6afc005010,
pad=0x1ac0480) at gstpad.c:5014
#53 gst_pad_send_event_unchecked (pad=0x1ac0480, event=0x7f6afc005010,
type=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at gstpad.c:5125
#54 0x00007f6b1bc31fd6 in gst_pad_push_event_unchecked (pad=0x1ac0250,
event=0x7f6afc005010,
type=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at gstpad.c:4830
#55 0x00007f6b1bc32438 in push_sticky (pad=0x1ac0250, ev=0x7f6b0f7fd6a0,
user_data=0x7f6b0f7fd710)
at gstpad.c:3434
#56 0x00007f6b1bc2fae2 in events_foreach (pad=0x1ac0250, func=0x7f6b1bc322e0
<push_sticky>,
user_data=0x7f6b0f7fd710) at gstpad.c:564
#57 0x00007f6b1bc3a3e8 in check_sticky (event=0x7f6afc0050f0, pad=0x1ac0250) at
gstpad.c:3490
#58 gst_pad_push_event (pad=0x1ac0250, event=0x7f6afc0050f0) at gstpad.c:4949
#59 0x00007f6b19a04114 in gst_base_transform_sink_eventfunc (trans=0x1abf8e0,
event=0x7f6afc0050f0)
at gstbasetransform.c:1902
#60 0x00007f6b1bc31733 in gst_pad_send_event_unchecked (pad=0x1ac0020,
event=0x7f6afc0050f0,
type=GST_PAD_PROBE_TYPE_IDLE) at gstpad.c:5132
#61 0x00007f6b1bc31fd6 in gst_pad_push_event_unchecked (pad=0x1aa1d80,
event=0x7f6afc0050f0,
type=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at gstpad.c:4830
#62 0x00007f6b1bc32438 in push_sticky (pad=0x1aa1d80, ev=0x7f6b0f7fd9c0,
user_data=0x7f6b0f7fda30)
at gstpad.c:3434
#63 0x00007f6b1bc2fae2 in events_foreach (pad=0x1aa1d80, func=0x7f6b1bc322e0
<push_sticky>,
user_data=0x7f6b0f7fda30) at gstpad.c:564
#64 0x00007f6b1bc3a3e8 in check_sticky (event=0x7f6afc0050f0, pad=0x1aa1d80) at
gstpad.c:3490
#65 gst_pad_push_event (pad=0x1aa1d80, event=0x7f6afc0050f0) at gstpad.c:4949
#66 0x00007f6b19a04114 in gst_base_transform_sink_eventfunc (trans=0x1abee60,
event=0x7f6afc0050f0)
at gstbasetransform.c:1902
#67 0x00007f6b1bc31733 in gst_pad_send_event_unchecked (pad=0x1aa1b50,
event=0x7f6afc0050f0,
---Type <return> to continue, or q <return> to quit---
type=GST_PAD_PROBE_TYPE_IDLE) at gstpad.c:5132
#68 0x00007f6b1bc31fd6 in gst_pad_push_event_unchecked (pad=0x1aa1920,
event=0x7f6afc0050f0,
type=GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM) at gstpad.c:4830
#69 0x00007f6b1bc32438 in push_sticky (pad=0x1aa1920, ev=0x7f6b0f7fdce0,
user_data=0x7f6b0f7fdd50)
at gstpad.c:3434
#70 0x00007f6b1bc2fae2 in events_foreach (pad=0x1aa1920, func=0x7f6b1bc322e0
<push_sticky>,
user_data=0x7f6b0f7fdd50) at gstpad.c:564
#71 0x00007f6b1bc3a3e8 in check_sticky (event=0x7f6afc0050f0, pad=0x1aa1920) at
gstpad.c:3490
#72 gst_pad_push_event (pad=0x1aa1920, event=0x7f6afc0050f0) at gstpad.c:4949
#73 0x00007f6b197c78d6 in gst_wavparse_loop (pad=<optimised out>) at
gstwavparse.c:2169
#74 0x00007f6b1bc623bf in gst_task_func (task=0x1b233b0) at gsttask.c:317
#75 0x00007f6b1b6b5b68 in g_thread_pool_thread_proxy (data=<optimised out>) at
gthreadpool.c:307
#76 0x00007f6b1b6b5305 in g_thread_proxy (data=0x1ac4800) at gthread.c:764
#77 0x00007f6b1b431e9a in start_thread (arg=0x7f6b0f7fe700) at
pthread_create.c:308
#78 0x00007f6b1b15e3fd in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#79 0x0000000000000000 in ?? ()
The other is alsasink closing out as the pipeline gets shutdown after the
error. Sometimes, _close gets called early enough that it unrefs the cached
caps which the other thread tries to use in the intersection.
The sequence of events seems to be:
- pipeline goes to PAUSED
- alsasink goes to PAUSED, async
- since it's async, the current state is not committed and stays in READY
- wavparse goes to PAUSED
- wavparse pushes in _loop
- push fails
- pipeline goes to NULL
- since alsasink is in READY, it does one down to NULL
- alsasink's _close is called, which unrefs the cached caps
- caps are queried, which uses the cached caps while they're being destroyed
I'm not sure why _loop is still running there, since it's been paused by the
failure to push, and an error was sent to the bus. It seems it's that same
wavparse, not the other.
--
Configure bugmail: https://bugzilla.gnome.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the QA contact for the bug.
You are the assignee for the bug.
More information about the gstreamer-bugs
mailing list