[Bug 702230] New: gst-plugins-base: spurious error from GstAlsaSrc

Fri Jun 14 03:12:18 PDT 2013

https://bugzilla.gnome.org/show_bug.cgi?id=702230
  GStreamer | gst-plugins-base | git

           Summary: gst-plugins-base: spurious error from GstAlsaSrc
    Classification: Platform
           Product: GStreamer
           Version: git
        OS/Version: Linux
            Status: UNCONFIRMED
          Severity: normal
          Priority: Normal
         Component: gst-plugins-base
        AssignedTo: gstreamer-bugs at lists.freedesktop.org
        ReportedBy: sebras at hotmail.com
         QAContact: gstreamer-bugs at lists.freedesktop.org
     GNOME version: ---

Created an attachment (id=246788)
 --> (https://bugzilla.gnome.org/attachment.cgi?id=246788)
Log with extra debug prints for audiobasesrc and ringbuffer.

The scenario is that we're trying to change a GstAlsaSrc PLAYING->READY.
When doing so I sometimes se the following error:

0:08:44.558564170 16779   0xd72030 ERROR             ringbuffer
gst-plugins-base/gst-libs/gst/audio/gstaudioringbuffer.c:1990:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer82>
Could not store timestamp, no timestamps buffer

I need some help in determining the correct way of solving this, but first let
me explain my reasoning:

I put a breakpoint on the GST_ERROR in gdb and obtained the following
backtraces

Thread 2 (Thread 3837):
#0  gst_audio_ring_buffer_set_timestamp (buf=0xc612c0, readseg=0, timestamp=?)
at gst-plugins-base/gst-libs/gst/audio/gstaudioringbuffer.c:1990
#1  0x742dd94c in audioringbuffer_thread_func (buf=0xc612c0) at
gst-plugins-base/gst-libs/gst/audio/gstaudiosrc.c:254
#2  0x7766e008 in g_thread_proxy (data=0xca6c00) at glib/glib/gthread.c:801
#3  0x775cb5b8 in start_thread (arg=0x729194b0) at pthread_create.c:310
#4  0x772b6cfc in __thread_start () from /lib/libc.so.6
Backtrace stopped: frame did not save the PC

Thread 1 (Thread 3645):
#0  0x775cc7fc in pthread_join (threadid=1922143408, thread_return=0x0) at
pthread_join.c:89
#1  0x776911b0 in g_system_thread_wait (thread=0xca6c00) at
glib/glib/gthread-posix.c:1158
#2  0x7766e6ec in g_thread_join (thread=0xca6c00) at glib/glib/gthread.c:966
#3  0x742dd494 in gst_audio_src_ring_buffer_release (buf=0xc612c0) at
gst-plugins-base/gst-libs/gst/audio/gstaudiosrc.c:435
#4  0x742b160c in gst_audio_ring_buffer_release (buf=0xc612c0) at
gst-plugins-base/gst-libs/gst/audio/gstaudioringbuffer.c:678
#5  0x742da584 in gst_audio_base_src_change_state (element=?) at
gst-plugins-base/gst-libs/gst/audio/gstaudiobasesrc.c:1170
#6  0x7661415c in gst_alsasrc_change_state (element=0xc3e650,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at
gst-plugins-base/ext/alsa/gstalsasrc.c:257
#7  0x777dae98 in gst_element_change_state (element=0xc3e650, transition=?) at
gstreamer/gst/gstelement.c:2605
#8  0x777dbaa0 in gst_element_set_state_func (element=0xc3e650, state=?) at
gstreamer/gst/gstelement.c:2561
#9  0x777b666c in gst_bin_element_set_state (element=0xc948f0,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at gstreamer/gst/gstbin.c:2297
#10 gst_bin_change_state_func (element=0xc948f0,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at gstreamer/gst/gstbin.c:2599
#11 0x77803278 in gst_pipeline_change_state (element=0xc948f0,
transition=GST_STATE_CHANGE_PAUSED_TO_READY) at gstreamer/gst/gstpipeline.c:471
#12 0x777dae98 in gst_element_change_state (element=0xc948f0, transition=?) at
gstreamer/gst/gstelement.c:2605
#13 0x777db208 in gst_element_change_state (element=0xc948f0, transition=?) at
gstreamer/gst/gstelement.c:2649
#14 0x777dbaa0 in gst_element_set_state_func (element=0xc948f0, state=?) at
gstreamer/gst/gstelement.c:2561
#15 0x004164b8 in pipeline_info_unref (pinfo=0xc54040) at
apps/monolith/monolith/src/cache.c:342
#16 0x00417cc0 in cache_info_free (cinfo=0xc9dfd8) at
apps/monolith/monolith/src/cache.c:714
#17 0x00416444 in pipeline_info_unref (pinfo=0xc76308) at
apps/monolith/monolith/src/cache.c:365
#18 0x00417cc0 in cache_info_free (cinfo=0xc50f98) at
apps/monolith/monolith/src/cache.c:714
#19 0x00416444 in pipeline_info_unref (pinfo=0xc810e8) at
apps/monolith/monolith/src/cache.c:365
#20 0x00417cc0 in cache_info_free (cinfo=0xc68018) at
apps/monolith/monolith/src/cache.c:714
#21 0x7773a2b4 in weak_refs_notify (data=0xc7dd20) at
glib/gobject/gobject.c:2464
#22 0x7773b9e8 in g_object_unref (_object=0xc5c7f8) at
glib/gobject/gobject.c:2981
#23 0x777aeb80 in gst_bin_remove_func (bin=0xc59bd0, element=0xc5c7f8) at
gstreamer/gst/gstbin.c:1536
#24 0x777b4870 in gst_bin_dispose (object=0xc59bd0) at
gstreamer/gst/gstbin.c:526
#25 0x7773b9e8 in g_object_unref (_object=0xc59bd0) at
glib/gobject/gobject.c:2981
#26 0x77922424 in gst_rtsp_media_finalize (obj=0xc598a0) at
gst-rtsp-server-2e835cfd47c33f89863651debf07d42c432d97a9/gst-rtsp-server/gst/rtsp-server/rtsp-media.c:255
#27 0x7773bad8 in g_object_unref (_object=0xc598a0) at
glib/gobject/gobject.c:3018
#28 0x77937234 in gst_rtsp_client_finalize (obj=0xba5b60) at
gst-rtsp-server-2e835cfd47c33f89863651debf07d42c432d97a9/gst-rtsp-server/gst/rtsp-server/rtsp-client.c:287
#29 0x7773bad8 in g_object_unref (_object=0xba5b60) at
glib/gobject/gobject.c:3018
#30 0x7763d0c4 in g_source_unref_internal (source=0xcd2800, context=0xc1b4d8,
have_lock=1) at glib/glib/gmain.c:1649
#31 0x776407fc in g_main_dispatch (context=0xc1b4d8) at glib/glib/gmain.c:2567
#32 g_main_context_dispatch (context=0xc1b4d8) at glib/glib/gmain.c:3075
#33 0x77640b50 in g_main_context_iterate (context=0xc1b4d8, block=?) at
glib/glib/gmain.c:3146
#34 0x77641180 in g_main_loop_run (loop=0xc2f3e0) at glib/glib/gmain.c:3340
#35 0x0040c07c in main (argc=1, argv=0x7fd2ec14) at
apps/monolith/monolith/src/main.c:557

My analysis of what is happening is that by making GstAlsaSrc transition
PLAYING->READY then gst_audio_base_src_change_state() will be called once for
each transition PLAYING->PAUSED and PAUSED->READY:

gst_audio_base_src_change_state()
when going PLAYING->PAUSED calls
  gst_audio_ring_buffer_pause()
  which calls
    gst_audio_ring_buffer_pause_unlocked()
    which does not pause the sample-reading-thread
audioringbuffer_thread_func() in gstaudiosrc.c
    because gstaudiosrc does not override the virtual pause member in
GstAudioRingBuffer

gst_audio_base_src_change_state()
when going PAUSED->READY calls
  gst_audio_ring_buffer_release()
  which first calls
    gst_audio_ring_buffer_stop()
    which calls
      gst_audio_src_ring_buffer_stop()
      which does nothing with the sample-reading-thread
audioringbuffer_thread_func()
  and then gst_audio_ring_buffer_release() frees buf->timestamps
  before calling
    gst_audio_src_ring_buffer_release()
    which for the sample-reading-thread audioringbuffer_thread_func() calls
      g_thread_join()

All this the sample-reading-thread is busy doing this:

audioringbuffer_thread_func()
runs a loop reading sample data into the ringbuffer and calls
  gst_audio_ring_buffer_set_timestamp()
  which makes use of buf->timestamps

The problem is that when changing states in GstAudioSrc there is nothing
telling the sample-reading-thread to stop working on the ringbuffer (or more
specifically the ringbufffers' timestamps array). There must be something in
the code path somewhere to tell that thread to using the array before it is
freed by gst_audio_ring_buffer_release().

There is some code in gst_audio_src_ring_buffer_stop() that Wim commented out
in commit 265a494 in gst-plugins-base in 2008
#if 0
  GST_DEBUG ("stop, waiting...");
  GST_AUDIO_SRC_RING_BUFFER_WAIT (buf);
  GST_DEBUG ("stoped");
#endif

With the following motivation:

+       * gst-libs/gst/audio/gstaudiosrc.c: (gst_audioringbuffer_stop):
+       Disable a code path that is now called but causes a deadlock for some
+       reason and is unneeded.

This leads me to the tentative conclusion that either GstAudioSrcRingBuffer
needs to implement GstAudioRingBuffer virtual pause() member or the WAIT Wim
commented out _is_ necessary to make the sample-reading-thread stop reading
samples from the device.

Which solution is correct?

I also obtained a more comprehensive log output by using
GST_DEBUG=2,audiobasesrc:6,ringbuffer:6, though I'm unsure if this provides any
relevant information. This is attached in log.txt

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