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 731121 - alsasink: Race condition causes alsasink to use invalid caps when a pipeline fails to start
alsasink: Race condition causes alsasink to use invalid caps when a pipeline ...
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-plugins-base
git master
Other Linux
: Normal normal
: 1.3.3
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2014-06-02 18:10 UTC by Vincent Penquerc'h
Modified: 2014-06-03 14:21 UTC
See Also:
GNOME target: ---
GNOME version: ---



Description Vincent Penquerc'h 2014-06-02 18:10:24 UTC
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
    at gmessages.c line 311
  • #1 g_logv
    at gmessages.c line 1033
  • #2 g_log
    at gmessages.c line 1071
  • #3 gst_value_intersect
    at gstvalue.c line 4752
  • #4 gst_value_intersect_list
    at gstvalue.c line 3642
  • #5 gst_value_intersect_list
    at gstvalue.c line 3642
  • #6 gst_structure_intersect_field1
    at gststructure.c line 3152
  • #7 gst_structure_foreach
    at gststructure.c line 1126
  • #8 gst_structure_intersect
    at gststructure.c line 3198
  • #9 gst_caps_intersect_first
    at gstcaps.c line 1620
  • #10 gst_caps_intersect_full
    at gstcaps.c line 1659
  • #11 gst_alsasink_getcaps
    at gstalsasink.c line 292
  • #12 gst_base_sink_query_caps
    at gstbasesink.c line 580
  • #13 gst_base_sink_default_query
  • #14 gst_audio_base_sink_query_pad
    at gstaudiobasesink.c line 411
  • #15 gst_alsasink_query
    at gstalsasink.c line 404
  • #16 gst_alsasink_query
    at gstalsasink.c line 387
  • #17 gst_pad_query
    at gstpad.c line 3575
  • #18 gst_pad_peer_query
    at gstpad.c line 3706
  • #19 gst_pad_peer_query_caps
    at gstutils.c line 2815
  • #20 gst_base_transform_query_caps
    at gstbasetransform.c line 715
  • #21 gst_base_transform_default_query
    at gstbasetransform.c line 1535
  • #22 gst_pad_query
    at gstpad.c line 3575
  • #23 gst_pad_peer_query
    at gstpad.c line 3706
  • #24 query_caps_func
    at gstutils.c line 2485
  • #25 gst_pad_forward
    at gstpad.c line 2787
  • #26 gst_pad_proxy_query_caps
    at gstutils.c line 2535
  • #27 gst_pad_query_caps_default
    at gstpad.c line 2959
  • #28 gst_pad_query_default
    at gstpad.c line 3070
  • #29 gst_pad_query
    at gstpad.c line 3575
  • #30 gst_pad_peer_query
    at gstpad.c line 3706
  • #31 gst_pad_peer_query_caps
    at gstutils.c line 2815
  • #32 gst_adder_sink_getcaps
    at gstadder.c line 249
  • #33 gst_adder_sink_query
    at gstadder.c line 323
  • #34 gst_adder_sink_query
  • #35 gst_collect_pads_query
    at gstcollectpads.c line 2091
  • #36 gst_pad_query
    at gstpad.c line 3575
  • #37 gst_pad_query_caps
    at gstutils.c line 2769
  • #38 gst_pad_query_accept_caps_default
    at gstpad.c line 2922
  • #39 gst_pad_query_default
    at gstpad.c line 3066
  • #40 gst_collect_pads_query_default
    at gstcollectpads.c line 2046
  • #41 gst_adder_sink_query
    at gstadder.c line 330
  • #42 gst_collect_pads_query
    at gstcollectpads.c line 2091
  • #43 gst_pad_query
    at gstpad.c line 3575
  • #44 gst_pad_peer_query
    at gstpad.c line 3706
  • #45 query_accept_caps_func
    at gstutils.c line 2425
  • #46 gst_pad_forward
    at gstpad.c line 2787
  • #47 gst_pad_proxy_query_accept_caps
    at gstutils.c line 2465
  • #48 gst_pad_query_accept_caps_default
    at gstpad.c line 2913
  • #49 gst_pad_query_default
    at gstpad.c line 3066
  • #50 gst_pad_query
    at gstpad.c line 3575
  • #51 gst_pad_query_accept_caps
  • #52 pre_eventfunc_check
    at gstpad.c line 5014
  • #53 gst_pad_send_event_unchecked
    at gstpad.c line 5125
  • #54 gst_pad_push_event_unchecked
    at gstpad.c line 4830
  • #55 push_sticky
    at gstpad.c line 3434
  • #56 events_foreach
    at gstpad.c line 564
  • #57 check_sticky
    at gstpad.c line 3490
  • #58 gst_pad_push_event
    at gstpad.c line 4949
  • #59 gst_base_transform_sink_eventfunc
    at gstbasetransform.c line 1902
  • #60 gst_pad_send_event_unchecked
    at gstpad.c line 5132
  • #61 gst_pad_push_event_unchecked
    at gstpad.c line 4830
  • #62 push_sticky
    at gstpad.c line 3434
  • #63 events_foreach
    at gstpad.c line 564
  • #64 check_sticky
    at gstpad.c line 3490
  • #65 gst_pad_push_event
    at gstpad.c line 4949
  • #66 gst_base_transform_sink_eventfunc
    at gstbasetransform.c line 1902
  • #67 gst_pad_send_event_unchecked
  • #68 gst_pad_push_event_unchecked
    at gstpad.c line 4830
  • #69 push_sticky
    at gstpad.c line 3434
  • #70 events_foreach
    at gstpad.c line 564
  • #71 check_sticky
    at gstpad.c line 3490
  • #72 gst_pad_push_event
    at gstpad.c line 4949
  • #73 gst_wavparse_loop
    at gstwavparse.c line 2169
  • #74 gst_task_func
    at gsttask.c line 317
  • #75 g_thread_pool_thread_proxy
    at gthreadpool.c line 307
  • #76 g_thread_proxy
    at gthread.c line 764
  • #77 start_thread
    at pthread_create.c line 308
  • #78 clone
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 112
  • #79 ??


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.
Comment 1 Vincent Penquerc'h 2014-06-03 14:18:51 UTC
commit 3b2d5833732a29672689badf3edf69867679e052
Author: Vincent Penquerc'h <vincent.penquerch@collabora.co.uk>
Date:   Tue Jun 3 15:10:33 2014 +0100

    alsasink: fix occasional crash intersecting invalid values
    
    When a pipeline using alsasink and push mode upstream fails
    to preroll, the following state will be the case:
    - A loop upstream will be PAUSED, pushing a first buffer
    - alsasink will be READY, pending PAUSED, because async
    
    On error, the pipeline will switch to NULL. alsasink is in
    READY, so goes to NULL immediately. It zeroes its cached
    caps. Meanwhile, the upstream loop can cause a caps query,
    conccurent with the state change. This will use those cached
    caps. If the zeroing happens between the NULL test and the
    dereferencing, GStreamer will critical down in the GstValue
    code.
    
    Since it appears that such a gap between states (PAUSED
    and pushing upstream, and NULL downstream) is expected, we
    need to protect the read/write access to the cached caps.
    
    This fixes the critical.
    
    See https://bugzilla.gnome.org/show_bug.cgi?id=731121