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 785058 - rtsp-session: No handling for timeout=0 (never timeout)
rtsp-session: No handling for timeout=0 (never timeout)
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-rtsp-server
1.12.2
Other Linux
: Normal enhancement
: 1.13.1
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2017-07-18 11:32 UTC by Jonathan Karlsson
Modified: 2017-11-15 15:44 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Small handle of timeout=0 with a corresponding unit test (2.64 KB, patch)
2017-07-18 11:32 UTC, Jonathan Karlsson
needs-work Details | Review
gst-rtsp-server patch (2.65 KB, patch)
2017-08-09 10:01 UTC, Göran Jönsson
committed Details | Review
log with timestamps (4.49 KB, text/plain)
2017-08-09 12:20 UTC, Göran Jönsson
  Details

Description Jonathan Karlsson 2017-07-18 11:32:40 UTC
Created attachment 355817 [details] [review]
Small handle of timeout=0 with a corresponding unit test

According to the documentation, a timeout value of 0 means never timeout.
But there is no special handling of timeout=0.
Comment 1 Jonathan Karlsson 2017-07-18 11:38:10 UTC
I see that gst_pool_source_prepare and collect_timeout in rtsp-session-pool puts an initial timeout value of -1. With the patch and with timeout=0 would then infer that gst_pool_source_prepare would always return FALSE.
I'm not sure what that means further, but maybe some handling of the -1 return value from gst_rtsp_sessoin_next_timeout_usec should be put there as well.
Comment 2 Sebastian Dröge (slomo) 2017-08-08 12:32:11 UTC
Review of attachment 355817 [details] [review]:

Generally looks good

::: tests/check/gst/rtspserver.c
@@ +1571,3 @@
+  /* sleep more than the extra 5 seconds that are usually added in
+   * gst_rtsp_session_next_timeout_usec */
+  sleep (7);

This is a bit suboptimal, it makes the test very slow.
Comment 3 Göran Jönsson 2017-08-09 10:01:30 UTC
Created attachment 357244 [details] [review]
gst-rtsp-server patch

add new patch with better test.
Comment 4 Göran Jönsson 2017-08-09 12:20:00 UTC
Created attachment 357258 [details]
log with timestamps
Comment 5 Göran Jönsson 2017-08-09 12:23:46 UTC
Hi,

When you write "I think this is quite error prone" , I assume you mean my
analyze and fix. I also aware that the code I complain about is around 5 
years old according to git blame. So I am understanding your concerns. 

So I suggest we take first thing first and I will try
to convince you, that the current implementation have problems.  
Then after that I am more then willing to discuss another solutions. 

Previously I showed with my Ftrace that snd_pcm_readi and  snd_pcm_status_get_state
is updating the tstamp .

If you now with that knowlage take a look at the code in gstalsasrc.c
functions gst_alsasrc_read and gst_alsasrc_get_timestamp and imagine that
a context-switch occur as in example below. Let say the thread don't
execute for 10 ms . 


gst_alsasrc_get_timestamp (GstAlsaSrc * asrc)
{
  snd_pcm_status_t *status;
  snd_htimestamp_t audiostamp;
  GstClockTime timestamp;
  snd_pcm_uframes_t avail;
  gint err = -EPIPE;

  if (G_UNLIKELY (!asrc)) {
    GST_ERROR_OBJECT (asrc, "No alsa handle created yet !");
    return GST_CLOCK_TIME_NONE;
  }

  if (G_UNLIKELY (snd_pcm_status_malloc (&status) != 0)) {
    GST_ERROR_OBJECT (asrc, "snd_pcm_status_malloc failed");
    return GST_CLOCK_TIME_NONE;
  }

  <---- context switch ------->

  if (G_UNLIKELY (snd_pcm_status (asrc->handle, status) != 0)) {
    GST_ERROR_OBJECT (asrc, "snd_pcm_status failed");
    return GST_CLOCK_TIME_NONE;
  }
  

Will the timestamp be affected by the context switch ?
Answer: Yes and that is the problem .

This part is also worth  looking at.

  /* max available frames sets the depth of the buffer */
  avail = snd_pcm_status_get_avail (status);

  /* calculate the timestamp of the next sample to be read */
  timestamp -= gst_util_uint64_scale_int (avail, GST_SECOND, asrc->rate);


Hier there are some handling that are compensate for long time context switch.
avail will be zero if the context switch is smaller than the time between two
IRQs . In the case I am investigate we have configured is so each packet 
represent 64ms audio. This mean that the timestamp can be 63.999,,, ms 
wrong in worst case .

I have also done some more instrumentation to simulate context-switchar

static gint test = 0;

gst_alsasrc_get_timestamp (GstAlsaSrc * asrc)
{
  snd_pcm_status_t *status;
  snd_htimestamp_t audiostamp;
  GstClockTime timestamp;
  snd_pcm_uframes_t avail;
  gint err = -EPIPE;

  if (G_UNLIKELY (!asrc)) {
    GST_ERROR_OBJECT (asrc, "No alsa handle created yet !");
    return GST_CLOCK_TIME_NONE;
  }

  if (G_UNLIKELY (snd_pcm_status_malloc (&status) != 0)) {
    GST_ERROR_OBJECT (asrc, "snd_pcm_status_malloc failed");
    return GST_CLOCK_TIME_NONE;
  }

  /* Simulate contex-switch */
  test++;
  if ((test%5) == 0) {
    GST_ERROR("Hello Simulated context-switch");
    g_usleep(50000); 
  }  


  if (G_UNLIKELY (snd_pcm_status (asrc->handle, status) != 0)) {
    GST_ERROR_OBJECT (asrc, "snd_pcm_status failed");
    return GST_CLOCK_TIME_NONE;
  }

,,,,

  avail = snd_pcm_status_get_avail (status);

  GST_ERROR("Hello avail %d",avail);

,,,,

  GST_ERROR_OBJECT (asrc, "ALSA timestamp : %" GST_TIME_FORMAT
      ", delay %lu", GST_TIME_ARGS (timestamp), avail);


Please find part of log attached timestamps.txt
In this log you can see that the timestamps after the 
"Hello Simulated context-switch" print are affected .
Normallt there are around 64ms between timestamps but after that simulated 
contex-switch the delta is much higher.

Do you agree on that current implementation have problems ?
Comment 6 Göran Jönsson 2017-08-09 12:26:47 UTC
Sorry the attachment and my last comment is for another issue.
Comment 7 Jonathan Karlsson 2017-08-15 05:53:36 UTC
Slomo: The reason for the sleep (7) was because there were already three other timeout tests that used this approach :) But I think it looks much better now with Göran's patch!
Comment 8 Jonathan Karlsson 2017-08-17 08:07:57 UTC
Do you also think the patch looks OK now?
Comment 9 Jonathan Karlsson 2017-11-10 09:31:39 UTC
slomo: Did you look at this patch again since the update from Göran?

Regards,
Jonathan
Comment 10 Sebastian Dröge (slomo) 2017-11-15 15:32:16 UTC
commit 0f87202a71e5560491be66182773e923f7b094ab (HEAD -> master)
Author: Jonathan Karlsson <jonakn@axis.com>
Date:   Wed Aug 9 11:52:38 2017 +0200

    rtsp-session: Handle the case when timeout=0
    
    According to the documentation, a timeout of value 0 means
    that the session never timeouts. This adds handling of that.
    If timeout=0 we just return with a -1 from
    gst_rtsp_session_next_timeout_usec ().
    
    https://bugzilla.gnome.org/show_bug.cgi?id=785058