avwait: Start video and audio together if audio starts late

Also add test to meson

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

gst/timecode/gstavwait.c

@@ -262,9 +262,12 @@ gst_avwait_init (GstAvWait * self)
 
   self->running_time_to_wait_for = GST_CLOCK_TIME_NONE;
   self->last_seen_video_running_time = GST_CLOCK_TIME_NONE;
+  self->first_audio_running_time = GST_CLOCK_TIME_NONE;
   self->last_seen_tc = NULL;
 
   self->video_eos_flag = FALSE;
+  self->audio_eos_flag = FALSE;
+  self->video_flush_flag = FALSE;
   self->audio_flush_flag = FALSE;
   self->shutdown_flag = FALSE;
   self->dropping = TRUE;
@@ -281,6 +284,7 @@ gst_avwait_init (GstAvWait * self)
   gst_video_info_init (&self->vinfo);
   g_mutex_init (&self->mutex);
   g_cond_init (&self->cond);
+  g_cond_init (&self->audio_cond);
 }
 
 static void
@@ -308,12 +312,15 @@ gst_avwait_change_state (GstElement * element, GstStateChange transition)
       g_mutex_lock (&self->mutex);
       self->shutdown_flag = TRUE;
       g_cond_signal (&self->cond);
+      g_cond_signal (&self->audio_cond);
       g_mutex_unlock (&self->mutex);
       break;
     case GST_STATE_CHANGE_READY_TO_PAUSED:
       g_mutex_lock (&self->mutex);
       self->shutdown_flag = FALSE;
       self->video_eos_flag = FALSE;
+      self->audio_eos_flag = FALSE;
+      self->video_flush_flag = FALSE;
       self->audio_flush_flag = FALSE;
       g_mutex_unlock (&self->mutex);
     default:
@@ -342,6 +349,7 @@ gst_avwait_change_state (GstElement * element, GstStateChange transition)
       self->vsegment.position = GST_CLOCK_TIME_NONE;
       gst_video_info_init (&self->vinfo);
       self->last_seen_video_running_time = GST_CLOCK_TIME_NONE;
+      self->first_audio_running_time = GST_CLOCK_TIME_NONE;
       if (self->last_seen_tc)
         gst_video_time_code_free (self->last_seen_tc);
       self->last_seen_tc = NULL;
@@ -371,6 +379,7 @@ gst_avwait_finalize (GObject * object)
 
   g_mutex_clear (&self->mutex);
   g_cond_clear (&self->cond);
+  g_cond_clear (&self->audio_cond);
 
   G_OBJECT_CLASS (parent_class)->finalize (object);
 }
@@ -613,8 +622,15 @@ gst_avwait_vsink_event (GstPad * pad, GstObject * parent, GstEvent * event)
       g_cond_signal (&self->cond);
       g_mutex_unlock (&self->mutex);
       break;
+    case GST_EVENT_FLUSH_START:
+      g_mutex_lock (&self->mutex);
+      self->video_flush_flag = TRUE;
+      g_cond_signal (&self->audio_cond);
+      g_mutex_unlock (&self->mutex);
+      break;
     case GST_EVENT_FLUSH_STOP:
       g_mutex_lock (&self->mutex);
+      self->video_flush_flag = FALSE;
       if (self->mode != MODE_RUNNING_TIME) {
         GST_DEBUG_OBJECT (self, "First time reset in video flush");
         self->running_time_to_wait_for = GST_CLOCK_TIME_NONE;
@@ -681,6 +697,12 @@ gst_avwait_asink_event (GstPad * pad, GstObject * parent, GstEvent * event)
       g_cond_signal (&self->cond);
       g_mutex_unlock (&self->mutex);
       break;
+    case GST_EVENT_EOS:
+      g_mutex_lock (&self->mutex);
+      self->audio_eos_flag = TRUE;
+      g_cond_signal (&self->audio_cond);
+      g_mutex_unlock (&self->mutex);
+      break;
     case GST_EVENT_FLUSH_STOP:
       g_mutex_lock (&self->mutex);
       self->audio_flush_flag = FALSE;
@@ -715,6 +737,7 @@ gst_avwait_vsink_chain (GstPad * pad, GstObject * parent, GstBuffer * inbuf)
   GstClockTime running_time;
   GstVideoTimeCode *tc = NULL;
   GstVideoTimeCodeMeta *tc_meta;
+  gboolean retry = FALSE;
 
   timestamp = GST_BUFFER_TIMESTAMP (inbuf);
   if (timestamp == GST_CLOCK_TIME_NONE) {
@@ -736,6 +759,18 @@ gst_avwait_vsink_chain (GstPad * pad, GstObject * parent, GstBuffer * inbuf)
     }
     self->last_seen_tc = tc;
   }
+  while (self->mode == MODE_VIDEO_FIRST
+      && self->first_audio_running_time == GST_CLOCK_TIME_NONE
+      && !self->audio_eos_flag
+      && !self->shutdown_flag && !self->video_flush_flag) {
+    g_cond_wait (&self->audio_cond, &self->mutex);
+  }
+  if (self->video_flush_flag || self->shutdown_flag) {
+    GST_DEBUG_OBJECT (self, "Shutting down, ignoring buffer");
+    gst_buffer_unref (inbuf);
+    g_mutex_unlock (&self->mutex);
+    return GST_FLOW_FLUSHING;
+  }
   switch (self->mode) {
     case MODE_TIMECODE:{
       if (self->tc != NULL && tc != NULL) {
@@ -850,25 +885,40 @@ gst_avwait_vsink_chain (GstPad * pad, GstObject * parent, GstBuffer * inbuf)
           "Recording started at %" GST_TIME_FORMAT " waiting for %"
           GST_TIME_FORMAT " inbuf %p", GST_TIME_ARGS (running_time),
           GST_TIME_ARGS (self->running_time_to_wait_for), inbuf);
-      if (running_time < self->running_time_to_end_at ||
+      if (self->mode != MODE_VIDEO_FIRST ||
-          self->running_time_to_end_at == GST_CLOCK_TIME_NONE) {
+          self->first_audio_running_time <= running_time ||
-        /* We are before the end of the recording. Check if we just actually
+          self->audio_eos_flag) {
-         * started */
+        if (running_time < self->running_time_to_end_at ||
-        if (running_time > self->running_time_to_wait_for) {
+            self->running_time_to_end_at == GST_CLOCK_TIME_NONE) {
-          /* We just started recording: synchronise the audio */
+          /* We are before the end of the recording. Check if we just actually
-          self->audio_running_time_to_wait_for = running_time;
+           * started */
-          gst_avwait_send_element_message (self, FALSE, running_time);
+          if (running_time > self->running_time_to_wait_for) {
-        } else {
+            /* We just started recording: synchronise the audio */
-          /* We will start in the future when running_time_to_wait_for is
+            self->audio_running_time_to_wait_for = running_time;
-           * reached */
+            gst_avwait_send_element_message (self, FALSE, running_time);
-          self->audio_running_time_to_wait_for = self->running_time_to_wait_for;
+          } else {
+            /* We will start in the future when running_time_to_wait_for is
+             * reached */
+            self->audio_running_time_to_wait_for =
+                self->running_time_to_wait_for;
+          }
+          self->audio_running_time_to_end_at = self->running_time_to_end_at;
         }
-        self->audio_running_time_to_end_at = self->running_time_to_end_at;
+      } else {
+        /* We are in video-first mode and behind the first audio timestamp. We
+         * should drop all video buffers until the first audio timestamp, so
+         * we can catch up with it. (In timecode mode and running-time mode, we
+         * don't care about when the audio starts, we start as soon as the
+         * target timecode or running time has been reached) */
+        gst_buffer_unref (inbuf);
+        inbuf = NULL;
+        retry = TRUE;
       }
     }
   }
 
-  self->was_recording = self->recording;
+  if (!retry)
+    self->was_recording = self->recording;
   g_cond_signal (&self->cond);
   g_mutex_unlock (&self->mutex);
   if (inbuf)
@@ -922,6 +972,10 @@ gst_avwait_asink_chain (GstPad * pad, GstObject * parent, GstBuffer * inbuf)
     GST_ERROR_OBJECT (self, "Could not get current running time");
     return GST_FLOW_ERROR;
   }
+  if (self->first_audio_running_time == GST_CLOCK_TIME_NONE) {
+    self->first_audio_running_time = current_running_time;
+  }
+  g_cond_signal (&self->audio_cond);
   if (self->vsegment.format == GST_FORMAT_TIME) {
     vsign =
         gst_segment_to_running_time_full (&self->vsegment, GST_FORMAT_TIME,

gst/timecode/gstavwait.h

@@ -63,6 +63,7 @@ struct _GstAvWait
 
   GstClockTime running_time_to_wait_for;
   GstClockTime last_seen_video_running_time;
+  GstClockTime first_audio_running_time;
   GstVideoTimeCode *last_seen_tc;
 
   /* If running_time_to_wait_for has been reached but we are
@@ -75,6 +76,8 @@ struct _GstAvWait
   GstClockTime audio_running_time_to_end_at;
 
   gboolean video_eos_flag;
+  gboolean audio_eos_flag;
+  gboolean video_flush_flag;
   gboolean audio_flush_flag;
   gboolean shutdown_flag;
 
@@ -84,6 +87,7 @@ struct _GstAvWait
 
   GCond cond;
   GMutex mutex;
+  GCond audio_cond;
 };
 
 struct _GstAvWaitClass

tests/check/elements/avwait.c

@@ -40,6 +40,7 @@ static GstVideoTimeCode *end_tc;
 static GstClockTime target_running_time;
 static gboolean recording;
 static gint mode;
+static gboolean audio_late;
 
 static GstAudioInfo ainfo;
 
@@ -54,6 +55,12 @@ typedef struct _ElementPadAndSwitchType
   SwitchType switch_after_2s;
 } ElementPadAndSwitchType;
 
+typedef struct _PadAndBoolean
+{
+  GstPad *pad;
+  gboolean b;
+} PadAndBoolean;
+
 static void
 set_default_params (void)
 {
@@ -65,6 +72,7 @@ set_default_params (void)
   target_running_time = GST_CLOCK_TIME_NONE;
   recording = TRUE;
   mode = 2;
+  audio_late = FALSE;
 
   first_audio_timestamp = GST_CLOCK_TIME_NONE;
   last_audio_timestamp = GST_CLOCK_TIME_NONE;
@@ -114,12 +122,20 @@ static gpointer
 push_abuffers (gpointer data)
 {
   GstSegment segment;
-  GstPad *pad = data;
   gint i;
-  GstClockTime timestamp = 0;
   GstCaps *caps;
   guint buf_size = 1000;
   guint channels = 2;
+  PadAndBoolean *e = data;
+  GstPad *pad = e->pad;
+  gboolean audio_late = e->b;
+  GstClockTime timestamp;
+
+  if (audio_late) {
+    timestamp = 50 * GST_MSECOND;
+  } else {
+    timestamp = 0;
+  }
 
   gst_pad_send_event (pad, gst_event_new_stream_start ("test"));
 
@@ -195,6 +211,7 @@ test_avwait_generic (void)
   GThread *athread, *vthread;
   GstBus *bus;
   ElementPadAndSwitchType *e;
+  PadAndBoolean *pb;
 
   audio_buffer_count = 0;
   video_buffer_count = 0;
@@ -239,8 +256,11 @@ test_avwait_generic (void)
   e->element = avwait;
   e->pad = vsink;
   e->switch_after_2s = switch_after_2s;
+  pb = g_new0 (PadAndBoolean, 1);
+  pb->pad = asink;
+  pb->b = audio_late;
 
-  athread = g_thread_new ("athread", (GThreadFunc) push_abuffers, asink);
+  athread = g_thread_new ("athread", (GThreadFunc) push_abuffers, pb);
   vthread = g_thread_new ("vthread", (GThreadFunc) push_vbuffers, e);
 
   g_thread_join (vthread);
@@ -251,6 +271,7 @@ test_avwait_generic (void)
   gst_bus_set_flushing (bus, TRUE);
   gst_object_unref (bus);
   g_free (e);
+  g_free (pb);
   gst_pad_unlink (asrc, aoutput_sink);
   gst_object_unref (asrc);
   gst_pad_unlink (vsrc, voutput_sink);
@@ -282,7 +303,7 @@ GST_START_TEST (test_avwait_switch_to_false)
   recording = TRUE;
   switch_after_2s = SWITCH_FALSE;
   test_avwait_generic ();
-  fail_unless_equals_uint64 (first_audio_timestamp, 0);
+  fail_unless_equals_uint64 (first_audio_timestamp, first_video_timestamp);
   fail_unless_equals_uint64 (first_video_timestamp, 0);
   fail_unless_equals_uint64 (last_video_timestamp, 2 * GST_SECOND);
   fail_unless_equals_uint64 (last_audio_timestamp, 2 * GST_SECOND);
@@ -426,6 +447,17 @@ GST_START_TEST (test_avwait_3stc_switch_to_false)
 
 GST_END_TEST;
 
+GST_START_TEST (test_avwait_audio_late)
+{
+  set_default_params ();
+  recording = TRUE;
+  audio_late = TRUE;
+  test_avwait_generic ();
+  fail_unless_equals_uint64 (first_audio_timestamp, 50 * GST_MSECOND);
+  fail_unless_equals_uint64 (first_video_timestamp, 50 * GST_MSECOND);
+}
+
+GST_END_TEST;
 
 static Suite *
 avwait_suite (void)
@@ -444,6 +476,7 @@ avwait_suite (void)
   tcase_add_test (tc_chain, test_avwait_1stc_switch_to_false);
   tcase_add_test (tc_chain, test_avwait_3stc_switch_to_true);
   tcase_add_test (tc_chain, test_avwait_3stc_switch_to_false);
+  tcase_add_test (tc_chain, test_avwait_audio_late);
   suite_add_tcase (s, tc_chain);
 
   return s;

tests/check/meson.build

@@ -21,6 +21,7 @@ base_tests = [
   [['elements/assrender.c'], not ass_dep.found(), [ass_dep]],
   [['elements/autoconvert.c']],
   [['elements/autovideoconvert.c']],
+  [['elements/avwait.c']],
   [['elements/camerabin.c']],
   [['elements/compositor.c']],
   [['elements/curlhttpsink.c'], not curl_dep.found(), [curl_dep]],