X-Git-Url: http://review.tizen.org/git/?a=blobdiff_plain;f=plugins%2Ftracers%2Fgstlatency.c;h=0f6d5176de32d43bc812fbac58a7e43f3e137430;hb=a9bc30b51c697065fe509b3b7dbad4a46061ea07;hp=1edd1a5d924d1f906646db4c576555852796d314;hpb=30741e02061f73b8ebad7c5bd1e08c243bf6de5c;p=platform%2Fupstream%2Fgstreamer.git

diff --git a/plugins/tracers/gstlatency.c b/plugins/tracers/gstlatency.c
index 1edd1a5..0f6d517 100644
--- a/plugins/tracers/gstlatency.c
+++ b/plugins/tracers/gstlatency.c
@@ -19,11 +19,18 @@
  * Boston, MA 02110-1301, USA.
  */
 /**
- * SECTION:gstlatency
+ * SECTION:element-latencytracer
  * @short_description: log processing latency stats
  *
  * A tracing module that determines src-to-sink latencies by injecting custom
- * events at sources and process them at sinks.
+ * events at sources and process them at sinks. This elements supports tracing
+ * the entire pipeline latency and per element latency. By default, only
+ * pipeline latency is traced. The 'flags' parameter can be used to enabled
+ * element tracing.
+ *
+ * ```
+ * GST_TRACERS="latency(flags=pipeline+element)" GST_DEBUG=GST_TRACER:7 ./...
+ * ```
  */
 /* TODO(ensonic): if there are two sources feeding into a mixer/muxer and later
  * we fan-out with tee and have two sinks, each sink would get all two events,
@@ -48,9 +55,30 @@ GST_DEBUG_CATEGORY_STATIC (gst_latency_debug);
 G_DEFINE_TYPE_WITH_CODE (GstLatencyTracer, gst_latency_tracer, GST_TYPE_TRACER,
     _do_init);
 
+static void latency_query_stack_destroy (gpointer data);
+
 static GQuark latency_probe_id;
+static GQuark sub_latency_probe_id;
 static GQuark latency_probe_pad;
+static GQuark latency_probe_element;
+static GQuark latency_probe_element_id;
 static GQuark latency_probe_ts;
+static GQuark drop_sub_latency_quark;
+
+static GstTracerRecord *tr_latency;
+static GstTracerRecord *tr_element_latency;
+static GstTracerRecord *tr_element_reported_latency;
+
+/* The private stack for each thread */
+static GPrivate latency_query_stack =
+G_PRIVATE_INIT (latency_query_stack_destroy);
+
+struct LatencyQueryTableValue
+{
+  GstElement *peer_element;
+  guint64 min;
+  guint64 max;
+};
 
 /* data helpers */
 
@@ -87,81 +115,222 @@ get_real_pad_parent (GstPad * pad)
   return GST_ELEMENT_CAST (parent);
 }
 
-/* hooks */
+static void
+latency_query_table_value_destroy (gpointer data)
+{
+  struct LatencyQueryTableValue *v = data;
+
+  /* Unref the element */
+  if (v->peer_element) {
+    gst_object_unref (v->peer_element);
+    v->peer_element = NULL;
+  }
+
+  /* Destroy the structure */
+  g_free (v);
+}
 
 static void
-log_latency (const GstStructure * data, GstPad * sink_pad, guint64 sink_ts)
+latency_query_stack_destroy (gpointer data)
 {
-  GstPad *src_pad;
-  guint64 src_ts;
-  gchar *src, *sink;
+  GQueue *queue = data;
+  g_queue_free_full (queue, latency_query_table_value_destroy);
+}
 
-  gst_structure_id_get (data,
-      latency_probe_pad, GST_TYPE_PAD, &src_pad,
-      latency_probe_ts, G_TYPE_UINT64, &src_ts, NULL);
+static GQueue *
+local_latency_query_stack_get (void)
+{
+  /* Make sure the stack exists */
+  GQueue *stack = g_private_get (&latency_query_stack);
+  if (!stack) {
+    g_private_set (&latency_query_stack, g_queue_new ());
+    stack = g_private_get (&latency_query_stack);
+  }
 
-  src = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (src_pad));
-  sink = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (sink_pad));
+  g_assert (stack);
+  return stack;
+}
 
-  /* TODO(ensonic): report format is still unstable */
-  gst_tracer_log_trace (gst_structure_new ("latency",
-          "src", G_TYPE_STRING, src,
-          "sink", G_TYPE_STRING, sink,
-          "time", G_TYPE_UINT64, GST_CLOCK_DIFF (src_ts, sink_ts), NULL));
-  g_free (src);
-  g_free (sink);
+static struct LatencyQueryTableValue *
+local_latency_query_stack_pop (void)
+{
+  GQueue *stack = local_latency_query_stack_get ();
+  return g_queue_pop_tail (stack);
 }
 
 static void
-send_latency_probe (GstElement * parent, GstPad * pad, guint64 ts)
+local_latency_query_stack_push (struct LatencyQueryTableValue *value)
 {
-  if (parent && (!GST_IS_BIN (parent)) &&
-      GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) {
-    GstEvent *latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
-        gst_structure_new_id (latency_probe_id,
-            latency_probe_pad, GST_TYPE_PAD, pad,
-            latency_probe_ts, G_TYPE_UINT64, ts,
-            NULL));
-    gst_pad_push_event (pad, latency_probe);
-  }
+  GQueue *stack = local_latency_query_stack_get ();
+  g_queue_push_tail (stack, value);
 }
 
+/* hooks */
+
 static void
-do_push_buffer_pre (GstTracer * self, guint64 ts, GstPad * pad)
+log_latency (const GstStructure * data, GstElement * sink_parent,
+    GstPad * sink_pad, guint64 sink_ts)
 {
-  GstElement *parent = get_real_pad_parent (pad);
+  guint64 src_ts;
+  const char *src, *element_src, *id_element_src;
+  const GValue *value;
+  gchar *sink, *element_sink, *id_element_sink;
+
+  value = gst_structure_id_get_value (data, latency_probe_ts);
+  src_ts = g_value_get_uint64 (value);
+
+  value = gst_structure_id_get_value (data, latency_probe_pad);
+  src = g_value_get_string (value);
+
+  value = gst_structure_id_get_value (data, latency_probe_element);
+  element_src = g_value_get_string (value);
+
+  value = gst_structure_id_get_value (data, latency_probe_element_id);
+  id_element_src = g_value_get_string (value);
+
+  id_element_sink = g_strdup_printf ("%p", sink_parent);
+  element_sink = gst_element_get_name (sink_parent);
+  sink = gst_pad_get_name (sink_pad);
+  gst_tracer_record_log (tr_latency, id_element_src, element_src, src,
+      id_element_sink, element_sink, sink, GST_CLOCK_DIFF (src_ts, sink_ts),
+      sink_ts);
+  g_free (sink);
+  g_free (element_sink);
+  g_free (id_element_sink);
+}
+
+static void
+log_element_latency (const GstStructure * data, GstElement * parent,
+    GstPad * pad, guint64 sink_ts)
+{
+  guint64 src_ts;
+  gchar *pad_name, *element_name, *element_id;
+  const GValue *value;
+
+  element_id = g_strdup_printf ("%p", parent);
+  element_name = gst_element_get_name (parent);
+  pad_name = gst_pad_get_name (pad);
+
+  /* TODO filtering */
+
+  value = gst_structure_id_get_value (data, latency_probe_ts);
+  src_ts = g_value_get_uint64 (value);
 
-  send_latency_probe (parent, pad, ts);
+  gst_tracer_record_log (tr_element_latency, element_id, element_name, pad_name,
+      GST_CLOCK_DIFF (src_ts, sink_ts), sink_ts);
+
+  g_free (pad_name);
+  g_free (element_name);
+  g_free (element_id);
 }
 
 static void
-do_pull_range_pre (GstTracer * self, guint64 ts, GstPad * pad)
+send_latency_probe (GstLatencyTracer * self, GstElement * parent, GstPad * pad,
+    guint64 ts)
 {
   GstPad *peer_pad = GST_PAD_PEER (pad);
-  GstElement *parent = get_real_pad_parent (peer_pad);
+  GstElement *peer_parent = get_real_pad_parent (peer_pad);
+
+  /* allow for non-parented pads to send latency probes as used in e.g.
+   * rtspsrc for TCP connections */
+  if (peer_pad && (!parent || (!GST_IS_BIN (parent)))) {
+    gchar *pad_name, *element_name, *element_id;
+    GstEvent *latency_probe;
+
+    if (self->flags & GST_LATENCY_TRACER_FLAG_PIPELINE &&
+        GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) {
+      element_id = g_strdup_printf ("%p", parent);
+      element_name = gst_element_get_name (parent);
+      pad_name = gst_pad_get_name (pad);
+
+      latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
+          gst_structure_new_id (latency_probe_id,
+              latency_probe_element_id, G_TYPE_STRING, element_id,
+              latency_probe_element, G_TYPE_STRING, element_name,
+              latency_probe_pad, G_TYPE_STRING, pad_name,
+              latency_probe_ts, G_TYPE_UINT64, ts, NULL));
+
+      GST_DEBUG ("%s_%s: Sending latency event %p", GST_DEBUG_PAD_NAME (pad),
+          latency_probe);
+
+      g_free (pad_name);
+      g_free (element_name);
+      g_free (element_id);
+      gst_pad_push_event (pad, latency_probe);
+    }
 
-  send_latency_probe (parent, peer_pad, ts);
+    if (self->flags & GST_LATENCY_TRACER_FLAG_ELEMENT) {
+      element_id = g_strdup_printf ("%p", peer_parent);
+      element_name = gst_element_get_name (peer_parent);
+      pad_name = gst_pad_get_name (peer_pad);
+
+      latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
+          gst_structure_new_id (sub_latency_probe_id,
+              latency_probe_element_id, G_TYPE_STRING, element_id,
+              latency_probe_element, G_TYPE_STRING, element_name,
+              latency_probe_pad, G_TYPE_STRING, pad_name,
+              latency_probe_ts, G_TYPE_UINT64, ts, NULL));
+
+      GST_DEBUG ("%s_%s: Sending sub-latency event %p",
+          GST_DEBUG_PAD_NAME (pad), latency_probe);
+
+      gst_pad_push_event (pad, latency_probe);
+      g_free (pad_name);
+      g_free (element_name);
+      g_free (element_id);
+    }
+  }
 }
 
 static void
 calculate_latency (GstElement * parent, GstPad * pad, guint64 ts)
 {
+  GstElement *peer_parent = get_real_pad_parent (GST_PAD_PEER (pad));
+
   if (parent && (!GST_IS_BIN (parent)) &&
-      GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SINK)) {
-    GstEvent *ev = g_object_get_qdata ((GObject *) pad, latency_probe_id);
+      (!GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE))) {
+    GstEvent *ev;
+
+    /* FIXME unsafe use of peer */
+    if (GST_OBJECT_FLAG_IS_SET (peer_parent, GST_ELEMENT_FLAG_SINK)) {
+      ev = g_object_get_qdata ((GObject *) pad, latency_probe_id);
+      GST_DEBUG ("%s_%s: Should log full lantency now (event %p)",
+          GST_DEBUG_PAD_NAME (pad), ev);
+      if (ev) {
+        log_latency (gst_event_get_structure (ev), peer_parent,
+            GST_PAD_PEER (pad), ts);
+        g_object_set_qdata ((GObject *) pad, latency_probe_id, NULL);
+      }
+    }
 
-    log_latency (gst_event_get_structure (ev), pad, ts);
-    gst_event_unref (ev);
+    ev = g_object_get_qdata ((GObject *) pad, sub_latency_probe_id);
+    GST_DEBUG ("%s_%s: Should log sub lantency now (event %p)",
+        GST_DEBUG_PAD_NAME (pad), ev);
+    if (ev) {
+      log_element_latency (gst_event_get_structure (ev), parent, pad, ts);
+      g_object_set_qdata ((GObject *) pad, sub_latency_probe_id, NULL);
+    }
   }
 }
 
 static void
-do_push_buffer_post (GstTracer * self, guint64 ts, GstPad * pad)
+do_push_buffer_pre (GstTracer * tracer, guint64 ts, GstPad * pad)
 {
+  GstLatencyTracer *self = (GstLatencyTracer *) tracer;
+  GstElement *parent = get_real_pad_parent (pad);
+
+  send_latency_probe (self, parent, pad, ts);
+  calculate_latency (parent, pad, ts);
+}
+
+static void
+do_pull_range_pre (GstTracer * tracer, guint64 ts, GstPad * pad)
+{
+  GstLatencyTracer *self = (GstLatencyTracer *) tracer;
   GstPad *peer_pad = GST_PAD_PEER (pad);
   GstElement *parent = get_real_pad_parent (peer_pad);
 
-  calculate_latency (parent, peer_pad, ts);
+  send_latency_probe (self, parent, peer_pad, ts);
 }
 
 static void
@@ -172,73 +341,367 @@ do_pull_range_post (GstTracer * self, guint64 ts, GstPad * pad)
   calculate_latency (parent, pad, ts);
 }
 
+static GstPadProbeReturn
+do_drop_sub_latency_event (GstPad * pad, GstPadProbeInfo * info,
+    gpointer user_data)
+{
+  GstEvent *ev = info->data;
+  GstPadProbeReturn ret = GST_PAD_PROBE_OK;
+
+  if (GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
+    const GstStructure *data = gst_event_get_structure (ev);
+
+    if (gst_structure_get_name_id (data) == sub_latency_probe_id) {
+      /* FIXME unsafe peer pad usage */
+      GstPad *peer_pad = GST_PAD_PEER (pad);
+      GstElement *peer_parent = get_real_pad_parent (peer_pad);
+      const GValue *value;
+      gchar *element_id = g_strdup_printf ("%p", peer_parent);
+      gchar *pad_name = gst_pad_get_name (peer_pad);
+      const gchar *value_element_id, *value_pad_name;
+
+      /* Get the element id, element name and pad name from data */
+      value = gst_structure_id_get_value (data, latency_probe_element_id);
+      value_element_id = g_value_get_string (value);
+      value = gst_structure_id_get_value (data, latency_probe_pad);
+      value_pad_name = g_value_get_string (value);
+
+      if (!g_str_equal (value_element_id, element_id) ||
+          !g_str_equal (value_pad_name, pad_name)) {
+        GST_DEBUG ("%s_%s: Dropping sub-latency event",
+            GST_DEBUG_PAD_NAME (pad));
+        ret = GST_PAD_PROBE_DROP;
+      }
+
+      g_free (pad_name);
+      g_free (element_id);
+    }
+  }
+
+  return ret;
+}
+
 static void
 do_push_event_pre (GstTracer * self, guint64 ts, GstPad * pad, GstEvent * ev)
 {
+  GstElement *parent = get_real_pad_parent (pad);
   GstPad *peer_pad = GST_PAD_PEER (pad);
-  GstElement *parent = get_real_pad_parent (peer_pad);
+  GstElement *peer_parent = get_real_pad_parent (peer_pad);
 
   if (parent && (!GST_IS_BIN (parent)) &&
-      GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SINK)) {
-    if (GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
-      const GstStructure *data = gst_event_get_structure (ev);
-
-      if (gst_structure_get_name_id (data) == latency_probe_id) {
-        /* store event and calculate latency when the buffer that follows
-         * has been processed */
-        g_object_set_qdata ((GObject *) peer_pad, latency_probe_id,
-            gst_event_ref (ev));
+      (!GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) &&
+      GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
+    const GstStructure *data = gst_event_get_structure (ev);
+
+    /* if not set yet, add a pad probe that prevents sub-latency event from
+     * flowing further */
+    if (gst_structure_get_name_id (data) == latency_probe_id) {
+
+      if (!g_object_get_qdata ((GObject *) pad, drop_sub_latency_quark)) {
+        GST_DEBUG ("%s_%s: Adding pad probe to drop sub-latency event",
+            GST_DEBUG_PAD_NAME (pad));
+        gst_pad_add_probe (pad, GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM,
+            do_drop_sub_latency_event, NULL, NULL);
+        g_object_set_qdata ((GObject *) pad, drop_sub_latency_quark,
+            (gpointer) 1);
+      }
+
+      /* FIXME unsafe peer access */
+      if (GST_OBJECT_FLAG_IS_SET (peer_parent, GST_ELEMENT_FLAG_SINK)) {
+        /* store event so that we can calculate latency when the buffer that
+         * follows has been processed */
+        g_object_set_qdata_full ((GObject *) pad, latency_probe_id,
+            gst_event_ref (ev), (GDestroyNotify) gst_event_unref);
       }
     }
+
+    if (gst_structure_get_name_id (data) == sub_latency_probe_id) {
+      const GValue *value;
+      gchar *element_id = g_strdup_printf ("%p", peer_parent);
+      gchar *pad_name = gst_pad_get_name (peer_pad);
+      const gchar *value_element_id, *value_pad_name;
+
+      /* Get the element id, element name and pad name from data */
+      value = gst_structure_id_get_value (data, latency_probe_element_id);
+      value_element_id = g_value_get_string (value);
+      value = gst_structure_id_get_value (data, latency_probe_pad);
+      value_pad_name = g_value_get_string (value);
+
+      if (!g_str_equal (value_element_id, element_id) ||
+          !g_str_equal (value_pad_name, pad_name)) {
+        GST_DEBUG ("%s_%s: Storing sub-latency event",
+            GST_DEBUG_PAD_NAME (pad));
+        g_object_set_qdata_full ((GObject *) pad, sub_latency_probe_id,
+            gst_event_ref (ev), (GDestroyNotify) gst_event_unref);
+      }
+
+      g_free (pad_name);
+      g_free (element_id);
+    }
+  }
+}
+
+static void
+do_query_post (GstLatencyTracer * tracer, GstClockTime ts, GstPad * pad,
+    GstQuery * query, gboolean res)
+{
+  /* Only check for latency queries if flag is enabled */
+  if ((tracer->flags & GST_LATENCY_TRACER_FLAG_REPORTED_ELEMENT) &&
+      (GST_QUERY_TYPE (query) == GST_QUERY_LATENCY)) {
+    gboolean live;
+    guint64 min = 0, max = 0, min_prev = 0, max_prev = 0;
+    gchar *element_name, *element_id;
+    struct LatencyQueryTableValue *value;
+    GstElement *element = get_real_pad_parent (pad);
+    GstElement *peer_element = get_real_pad_parent (GST_PAD_PEER (pad));
+
+    /* Parse the query */
+    gst_query_parse_latency (query, &live, &min, &max);
+
+    /* Pop from stack */
+    value = local_latency_query_stack_pop ();
+    while (value && value->peer_element == element) {
+      min_prev = MAX (value->min, min_prev);
+      max_prev = MAX (value->max, max_prev);
+      value = local_latency_query_stack_pop ();
+    }
+
+    /* Push to stack */
+    value = g_new0 (struct LatencyQueryTableValue, 1);
+    value->peer_element = gst_object_ref (peer_element);
+    value->min = min;
+    value->max = max;
+    local_latency_query_stack_push (value);
+
+    /* Get the pad name */
+    element_id = g_strdup_printf ("%p", element);
+    element_name = gst_element_get_name (element);
+
+    /* Log reported latency */
+    gst_tracer_record_log (tr_element_reported_latency, element_id,
+        element_name, live, GST_CLOCK_DIFF (min_prev, min),
+        GST_CLOCK_DIFF (max_prev, max), ts);
+
+    /* Clean up */
+    g_free (element_name);
+    g_free (element_id);
   }
 }
 
 /* tracer class */
 
 static void
+gst_latency_tracer_constructed (GObject * object)
+{
+  GstLatencyTracer *self = GST_LATENCY_TRACER (object);
+  gchar *params, *tmp;
+  GstStructure *params_struct = NULL;
+
+  g_object_get (self, "params", &params, NULL);
+
+  if (!params)
+    return;
+
+  tmp = g_strdup_printf ("latency,%s", params);
+  params_struct = gst_structure_from_string (tmp, NULL);
+  g_free (tmp);
+
+  /* Read the flags if available */
+  if (params_struct) {
+    const gchar *flags = gst_structure_get_string (params_struct, "flags");
+
+    self->flags = 0;
+
+    if (flags) {
+      GStrv split = g_strsplit (flags, "+", -1);
+      gint i;
+
+      for (i = 0; split[i]; i++) {
+        if (g_str_equal (split[i], "pipeline"))
+          self->flags |= GST_LATENCY_TRACER_FLAG_PIPELINE;
+        else if (g_str_equal (split[i], "element"))
+          self->flags |= GST_LATENCY_TRACER_FLAG_ELEMENT;
+        else if (g_str_equal (split[i], "reported"))
+          self->flags |= GST_LATENCY_TRACER_FLAG_REPORTED_ELEMENT;
+        else
+          GST_WARNING ("Invalid latency tracer flags %s", split[i]);
+      }
+
+      g_strfreev (split);
+    }
+  }
+
+  g_free (params);
+}
+
+static void
 gst_latency_tracer_class_init (GstLatencyTracerClass * klass)
 {
+  GObjectClass *gobject_class = G_OBJECT_CLASS (klass);
+
+  gobject_class->constructed = gst_latency_tracer_constructed;
+
   latency_probe_id = g_quark_from_static_string ("latency_probe.id");
+  sub_latency_probe_id = g_quark_from_static_string ("sub_latency_probe.id");
   latency_probe_pad = g_quark_from_static_string ("latency_probe.pad");
+  latency_probe_element = g_quark_from_static_string ("latency_probe.element");
+  latency_probe_element_id =
+      g_quark_from_static_string ("latency_probe.element_id");
   latency_probe_ts = g_quark_from_static_string ("latency_probe.ts");
+  drop_sub_latency_quark =
+      g_quark_from_static_string ("drop_sub_latency.quark");
 
   /* announce trace formats */
   /* *INDENT-OFF* */
-  gst_tracer_log_trace (gst_structure_new ("latency.class",
+  tr_latency = gst_tracer_record_new ("latency.class",
+      "src-element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
+      "src-element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
       "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
-          "related-to", G_TYPE_STRING, "pad",  /* TODO: use genum */
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
+          NULL),
+      "sink-element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
+      "sink-element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
           NULL),
       "sink", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
-          "related-to", G_TYPE_STRING, "pad",  /* TODO: use genum */
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
           NULL),
       "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
           "description", G_TYPE_STRING,
               "time it took for the buffer to go from src to sink ns",
-          "flags", G_TYPE_STRING, "aggregated",  /* TODO: use gflags */
           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
           "max", G_TYPE_UINT64, G_MAXUINT64,
           NULL),
-      NULL));
+      "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING, "ts when the latency has been logged",
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      NULL);
+
+  tr_element_latency = gst_tracer_record_new ("element-latency.class",
+      "element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
+      "element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
+      "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
+          NULL),
+      "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING,
+              "time it took for the buffer to go from src to sink ns",
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING, "ts when the latency has been logged",
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      NULL);
+
+
+  tr_element_reported_latency = gst_tracer_record_new (
+      "element-reported-latency.class",
+      "element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
+      "element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "type", G_TYPE_GTYPE, G_TYPE_STRING,
+          "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
+          GST_TRACER_VALUE_SCOPE_ELEMENT,
+          NULL),
+      "live", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_BOOLEAN,
+          "description", G_TYPE_STRING,
+              "wether the it is a live stream or not",
+          NULL),
+      "min", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING,
+              "the minimum reported latency",
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      "max", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING, "the maximum reported latency",
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING, "ts when the latency has been reported",
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      NULL);
   /* *INDENT-ON* */
+
+  GST_OBJECT_FLAG_SET (tr_latency, GST_OBJECT_FLAG_MAY_BE_LEAKED);
+  GST_OBJECT_FLAG_SET (tr_element_latency, GST_OBJECT_FLAG_MAY_BE_LEAKED);
+  GST_OBJECT_FLAG_SET (tr_element_reported_latency,
+      GST_OBJECT_FLAG_MAY_BE_LEAKED);
 }
 
 static void
 gst_latency_tracer_init (GstLatencyTracer * self)
 {
   GstTracer *tracer = GST_TRACER (self);
+
+  /* only trace pipeline latency by default */
+  self->flags = GST_LATENCY_TRACER_FLAG_PIPELINE;
+
+  /* in push mode, pre/post will be called before/after the peer chain
+   * function has been called. For this reaosn, we only use -pre to avoid
+   * accounting for the processing time of the peer element (the sink) */
   gst_tracing_register_hook (tracer, "pad-push-pre",
       G_CALLBACK (do_push_buffer_pre));
   gst_tracing_register_hook (tracer, "pad-push-list-pre",
       G_CALLBACK (do_push_buffer_pre));
-  gst_tracing_register_hook (tracer, "pad-push-post",
-      G_CALLBACK (do_push_buffer_post));
-  gst_tracing_register_hook (tracer, "pad-push-list-post",
-      G_CALLBACK (do_push_buffer_post));
+
+  /* while in pull mode, pre/post will happen before and after the upstream
+   * pull_range call is made, so it already only account for the upstream
+   * processing time. As a side effect, in pull mode, we can measure the
+   * source processing latency, while in push mode, we can't */
   gst_tracing_register_hook (tracer, "pad-pull-range-pre",
       G_CALLBACK (do_pull_range_pre));
   gst_tracing_register_hook (tracer, "pad-pull-range-post",
       G_CALLBACK (do_pull_range_post));
+
   gst_tracing_register_hook (tracer, "pad-push-event-pre",
       G_CALLBACK (do_push_event_pre));
+
+  /* Add pad query post hook to get the reported per-element latency */
+  gst_tracing_register_hook (tracer, "pad-query-post",
+      G_CALLBACK (do_query_post));
 }