[Bug 796607] New: souphttpsrc: reference count error after flushing (race condition)

GStreamer (GNOME Bugzilla) bugzilla at gnome.org
Sat Jun 16 16:49:27 UTC 2018 

https://bugzilla.gnome.org/show_bug.cgi?id=796607

            Bug ID: 796607
           Summary: souphttpsrc: reference count error after flushing
                    (race condition)
    Classification: Platform
           Product: GStreamer
           Version: git master
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: Normal
         Component: gst-plugins-good
          Assignee: gstreamer-bugs at lists.freedesktop.org
          Reporter: aboya at igalia.com
        QA Contact: gstreamer-bugs at lists.freedesktop.org
     GNOME version: ---

This is an error I've encountered several times while running the gst-validate
adaptive test suite. It only happens a small fraction of the times a test is
run though.

I had best luck reproducing it with the following Bash command on GStreamer
master:

$ true; while [[ $? -eq 0 ]]; do echo "new run";
GST_DEBUG=souphttpsrc:9,adaptivedemux:9,dashdemux:9,queue:9
G_DEBUG=fatal-criticals GST_GL_XINITTHREADS='1' DISPLAY=':0'
GST_VALIDATE_SCENARIO='fast_forward'
GST_VALIDATE_OVERRIDE='/home/ntrrgc/gst-validate/gst-integration-testsuites/medias/adaptivecontent/BBCRD_ondemand_testcard_1_client_manifest-ctv-events.override'
GST_VALIDATE_SCENARIOS_PATH='/home/ntrrgc/Apps/gst-build/prefix/share/gstreamer-1.0/validate/scenarios:/home/ntrrgc/Apps/gst-build/subprojects/gst-devtools/validate/data/scenarios'
/home/ntrrgc/Apps/gst-build/build/subprojects/gst-devtools/validate/tools/gst-validate-1.0
playbin
uri=http://rdmedia.bbc.co.uk/dash/ondemand/testcard/1/client_manifest-ctv-events.mpd
audio-sink=fakesink sync=true video-sink=fakesink sync=true qos=true
max-lateness=20000000 --set-media-info
/home/ntrrgc/gst-validate/gst-integration-testsuites/medias/adaptivecontent/BBCRD_ondemand_testcard_1_client_manifest-ctv-events.stream_info
> ~/tmp/gst-log.txt 2>&1; done

It usually takes around 10 tries to manifest in my case. For some reason I had
no luck attempting to run the same test with `gst-validate-launcher -m
--forever
adaptive.dash.playback.fast_forward.BBCRD_ondemand_testcard_1_client_manifest-ctv-events`
even after 150 tries, although I have seen it many times by chance when running
the entire adaptive suite.

Start buffering
Buffering... 0%  ^M0:00:05.303023920 35680      0x16a4010 TRACE         
adaptivedemux gstadaptivedemux.c:1683:gst_adaptive_demux_handle_seek_event:
Locking from thread 0x16a4010
0:00:05.303073512 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:1683:gst_adaptive_demux_handle_seek_event: Locked from
thread 0x16a4010
0:00:05.303095751 35680      0x16a4010 LOG            adaptivedemux
gstadaptivedemux.c:2078:gst_adaptive_demux_stop_tasks:<dashdemux0> Stopping
tasks
0:00:05.303127989 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2097:gst_adaptive_demux_stop_tasks: Unlocking from thread
0x16a4010
0:00:05.303145020 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2101:gst_adaptive_demux_stop_tasks: Locking from thread
0x16a4010
0:00:05.303142650 35680 0x7fcbf0541720 DEBUG          adaptivedemux
gstadaptivedemux.c:3210:gst_adaptive_demux_stream_download_uri:<dashdemux0:audio_00>
Finished Waiting for fragment download:
http://rdmedia.bbc.co.uk/dash/ondemand/testcard/1/audio/128kbps/000023.m4s
0:00:05.303164565 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2101:gst_adaptive_demux_stop_tasks: Locked from thread
0x16a4010
0:00:05.303185940 35680 0x7fcbf0541720 TRACE          adaptivedemux
gstadaptivedemux.c:3212:gst_adaptive_demux_stream_download_uri: Locking from
thread 0x7fcbf0541720
0:00:05.303204570 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2118:gst_adaptive_demux_stop_tasks: Unlocking from thread
0x16a4010
0:00:05.303263193 35680 0x7fcbf0541720 TRACE          adaptivedemux
gstadaptivedemux.c:3212:gst_adaptive_demux_stream_download_uri: Locked from
thread 0x7fcbf0541720
0:00:05.303286738 35680 0x7fcbf0541720 DEBUG          adaptivedemux
gstadaptivedemux.c:3438:gst_adaptive_demux_stream_download_fragment:<dashdemux0:audio_00>
Fragment download result: -2 (200) flushing
0:00:05.303300415 35680 0x7fcbf0541720 DEBUG          adaptivedemux
gstadaptivedemux.c:3922:gst_adaptive_demux_stream_download_loop:<dashdemux0:audio_00>
Stream has been cancelled
0:00:05.303301583 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2130:gst_adaptive_demux_stop_tasks: Locking from thread
0x16a4010
0:00:05.303319092 35680 0x7fcbf0541720 TRACE          adaptivedemux
gstadaptivedemux.c:3916:gst_adaptive_demux_stream_download_loop: Unlocking from
thread 0x7fcbf0541720
0:00:05.303354321 35680 0x7fcbf0541720 LOG            adaptivedemux
gstadaptivedemux.c:3917:gst_adaptive_demux_stream_download_loop:<dashdemux0:audio_00>
download loop end
0:00:05.303361554 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2130:gst_adaptive_demux_stop_tasks: Locked from thread
0x16a4010
0:00:05.303377419 35680      0x16a4010 TRACE          adaptivedemux
gstadaptivedemux.c:2118:gst_adaptive_demux_stop_tasks: Unlocking from thread
0x16a4010
0:00:05.303753736 35680      0x16a4010 DEBUG            souphttpsrc
gstsouphttpsrc.c:1929:gst_soup_http_src_unlock:<souphttpsrc0> unlock()
0:00:05.304608040 35680 0x7fcbf05f1990 ERROR               validate
gst-validate-reporter.c:195:gst_validate_report_valist: <playbin0> 2335
(critical) : g-log: We got a g_log critical issue : g_main_context_ref:
assertion 'g_atomic_int_get (&context->ref_count) > 0' failed


(gdb) bt
#0  0x00007fcc1926e7e5 in _g_log_abort () at gmessages.c:580
#1  0x00007fcc1926fb1d in g_logv (log_domain=0x7fcc192b236e "GLib",
log_level=G_LOG_LEVEL_CRITICAL, format=<optimized out>,
args=args at entry=0x7fcbedea7390) at gmessages.c:1391
#2  0x00007fcc1926fcf3 in g_log (log_domain=log_domain at entry=0x7fcc192b236e
"GLib", log_level=log_level at entry=G_LOG_LEVEL_CRITICAL,
format=format at entry=0x7fcc192bbe47 "%s: assertion '%s' failed")
    at gmessages.c:1432
#3  0x00007fcc1927052d in g_return_if_fail_warning
(log_domain=log_domain at entry=0x7fcc192b236e "GLib",
pretty_function=pretty_function at entry=0x7fcc192ba8d0 <__func__.12788>
"g_main_context_ref", 
    expression=expression at entry=0x7fcc192b9c98 "g_atomic_int_get
(&context->ref_count) > 0") at gmessages.c:2809
#4  0x00007fcc19265d04 in g_main_context_ref (context=<optimized out>) at
gmain.c:519
#5  0x00007fcbf6e3296f in soup_socket_set_property (object=<optimized out>,
prop_id=18, value=0x7fcbedea7530, pspec=0x7fcbf0631660) at soup-socket.c:341
#6  0x00007fcc18fdfae5 in object_set_property (nqueue=0x7fcbdc002060,
value=0x7fcbedea75b0, pspec=0x7fcbf0631660, object=0x7fcbd40124d0) at
gobject.c:1441
#7  g_object_new_internal (class=class at entry=0x7fcbf04f0ae0,
params=params at entry=0x7fcbedea7680, n_params=n_params at entry=3) at
gobject.c:1853
#8  0x00007fcc18fe164e in g_object_new_valist (object_type=<optimized out>,
first_property_name=first_property_name at entry=0x7fcbf6e43ec5 "remote-address",
var_args=var_args at entry=0x7fcbedea77d0)
    at gobject.c:2122
#9  0x00007fcbf6e32f5c in soup_socket_new
(optname1=optname1 at entry=0x7fcbf6e43ec5 "remote-address") at soup-socket.c:825
#10 0x00007fcbf6e09f12 in soup_connection_connect_sync (conn=0x7fcb94b74730,
cancellable=0x7fcbf057eb60, error=error at entry=0x7fcbedea7950) at
soup-connection.c:453
#11 0x00007fcbf6e2efab in get_connection (should_cleanup=<optimized out>,
item=0x7fcbe0006b40) at soup-session.c:1956
#12 soup_session_process_queue_item (session=<optimized out>,
item=0x7fcbe0006b40, should_cleanup=<optimized out>, loop=<optimized out>) at
soup-session.c:1977
#13 0x00007fcbf6e2fcb0 in soup_session_send (session=0x16fe220,
msg=0x7fcbc40088a0, cancellable=<optimized out>, error=0x7fcbedea7a20) at
soup-session.c:4429
#14 0x00007fcbf70ad0fb in gst_soup_http_src_send_message (src=0x7fcbdc00c130)
at ../subprojects/gst-plugins-good/ext/soup/gstsouphttpsrc.c:1531
#15 0x00007fcbf70ad4d6 in gst_soup_http_src_do_request (src=0x7fcbdc00c130,
method=0x7fcbf70b356a "GET") at
../subprojects/gst-plugins-good/ext/soup/gstsouphttpsrc.c:1603
#16 0x00007fcbf70ae178 in gst_soup_http_src_create (psrc=0x7fcbdc00c130,
outbuf=0x7fcbedea7bb0) at
../subprojects/gst-plugins-good/ext/soup/gstsouphttpsrc.c:1804
#17 0x00007fcc1661c45c in gst_push_src_create (bsrc=0x7fcbdc00c130, offset=0,
length=32768, ret=0x7fcbedea7bb0) at
../subprojects/gstreamer/libs/gst/base/gstpushsrc.c:131
#18 0x00007fcc165fda9a in gst_base_src_get_range (src=0x7fcbdc00c130, offset=0,
length=32768, buf=0x7fcbedea7c58) at
../subprojects/gstreamer/libs/gst/base/gstbasesrc.c:2512
#19 0x00007fcc165fed75 in gst_base_src_loop (pad=0x7fcbf0542d30) at
../subprojects/gstreamer/libs/gst/base/gstbasesrc.c:2836
#20 0x00007fcc19610990 in gst_task_func (task=0x7fcbbc017950) at
../subprojects/gstreamer/gst/gsttask.c:332
#21 0x00007fcc19611b58 in default_func (tdata=0x7fcbb8002d30, pool=0x1440110)
at ../subprojects/gstreamer/gst/gsttaskpool.c:69
#22 0x00007fcc19291933 in g_thread_pool_thread_proxy (data=<optimized out>) at
gthreadpool.c:307
#23 0x00007fcc19290f2a in g_thread_proxy (data=0x7fcbf05f1990) at gthread.c:784
#24 0x00007fcc18a0e594 in start_thread (arg=<optimized out>) at
pthread_create.c:463
#25 0x00007fcc1874200f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:95

-- 
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