plugins/tracers/gstlatency.c

   1 /* GStreamer
   2  * Copyright (C) 2013 Stefan Sauer <ensonic@users.sf.net>
   3  *
   4  * gstlatency.c: tracing module that logs processing latency stats
   5  *
   6  * This library is free software; you can redistribute it and/or
   7  * modify it under the terms of the GNU Library General Public
   8  * License as published by the Free Software Foundation; either
   9  * version 2 of the License, or (at your option) any later version.
  10  *
  11  * This library is distributed in the hope that it will be useful,
  12  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  13  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  14  * Library General Public License for more details.
  15  *
  16  * You should have received a copy of the GNU Library General Public
  17  * License along with this library; if not, write to the
  18  * Free Software Foundation, Inc., 51 Franklin St, Fifth Floor,
  19  * Boston, MA 02110-1301, USA.
  20  */
  21 /**
  22  * SECTION:element-latencytracer
  23  * @short_description: log processing latency stats
  24  *
  25  * A tracing module that determines src-to-sink latencies by injecting custom
  26  * events at sources and process them at sinks. This elements supports tracing
  27  * the entire pipeline latency and per element latency. By default, only
  28  * pipeline latency is traced. The 'flags' parameter can be used to enabled
  29  * element tracing.
  30  *
  31  * ```
  32  * GST_TRACERS="latency(flags=pipeline+element)" GST_DEBUG=GST_TRACER:7 ./...
  33  * ```
  34  */
  35 /* TODO(ensonic): if there are two sources feeding into a mixer/muxer and later
  36  * we fan-out with tee and have two sinks, each sink would get all two events,
  37  * the later event would overwrite the former. Unfortunately when the buffer
  38  * arrives on the sink we don't know to which event it correlates. Better would
  39  * be to use the buffer meta in 1.0 instead of the event. Or we track a min/max
  40  * latency.
  41  */
  42
  43 #ifdef HAVE_CONFIG_H
  44 #  include "config.h"
  45 #endif
  46
  47 #include "gstlatency.h"
  48
  49 GST_DEBUG_CATEGORY_STATIC (gst_latency_debug);
  50 #define GST_CAT_DEFAULT gst_latency_debug
  51
  52 #define _do_init \
  53     GST_DEBUG_CATEGORY_INIT (gst_latency_debug, "latency", 0, "latency tracer");
  54 #define gst_latency_tracer_parent_class parent_class
  55 G_DEFINE_TYPE_WITH_CODE (GstLatencyTracer, gst_latency_tracer, GST_TYPE_TRACER,
  56     _do_init);
  57
  58 static void latency_query_stack_destroy (gpointer data);
  59
  60 static GQuark latency_probe_id;
  61 static GQuark sub_latency_probe_id;
  62 static GQuark latency_probe_pad;
  63 static GQuark latency_probe_element;
  64 static GQuark latency_probe_element_id;
  65 static GQuark latency_probe_ts;
  66 static GQuark drop_sub_latency_quark;
  67
  68 static GstTracerRecord *tr_latency;
  69 static GstTracerRecord *tr_element_latency;
  70 static GstTracerRecord *tr_element_reported_latency;
  71
  72 /* The private stack for each thread */
  73 static GPrivate latency_query_stack =
  74 G_PRIVATE_INIT (latency_query_stack_destroy);
  75
  76 struct LatencyQueryTableValue
  77 {
  78   GstElement *peer_element;
  79   guint64 min;
  80   guint64 max;
  81 };
  82
  83 /* data helpers */
  84
  85 /*
  86  * Get the element/bin owning the pad.
  87  *
  88  * in: a normal pad
  89  * out: the element
  90  *
  91  * in: a proxy pad
  92  * out: the element that contains the peer of the proxy
  93  *
  94  * in: a ghost pad
  95  * out: the bin owning the ghostpad
  96  */
  97 /* TODO(ensonic): gst_pad_get_parent_element() would not work here, should we
  98  * add this as new api, e.g. gst_pad_find_parent_element();
  99  */
 100 static GstElement *
 101 get_real_pad_parent (GstPad * pad)
 102 {
 103   GstObject *parent;
 104
 105   if (!pad)
 106     return NULL;
 107
 108   parent = GST_OBJECT_PARENT (pad);
 109
 110   /* if parent of pad is a ghost-pad, then pad is a proxy_pad */
 111   if (parent && GST_IS_GHOST_PAD (parent)) {
 112     pad = GST_PAD_CAST (parent);
 113     parent = GST_OBJECT_PARENT (pad);
 114   }
 115   return GST_ELEMENT_CAST (parent);
 116 }
 117
 118 static void
 119 latency_query_table_value_destroy (gpointer data)
 120 {
 121   struct LatencyQueryTableValue *v = data;
 122
 123   /* Unref the element */
 124   if (v->peer_element) {
 125     gst_object_unref (v->peer_element);
 126     v->peer_element = NULL;
 127   }
 128
 129   /* Destroy the structure */
 130   g_free (v);
 131 }
 132
 133 static void
 134 latency_query_stack_destroy (gpointer data)
 135 {
 136   GQueue *queue = data;
 137   g_queue_free_full (queue, latency_query_table_value_destroy);
 138 }
 139
 140 static GQueue *
 141 local_latency_query_stack_get (void)
 142 {
 143   /* Make sure the stack exists */
 144   GQueue *stack = g_private_get (&latency_query_stack);
 145   if (!stack) {
 146     g_private_set (&latency_query_stack, g_queue_new ());
 147     stack = g_private_get (&latency_query_stack);
 148   }
 149
 150   g_assert (stack);
 151   return stack;
 152 }
 153
 154 static struct LatencyQueryTableValue *
 155 local_latency_query_stack_pop (void)
 156 {
 157   GQueue *stack = local_latency_query_stack_get ();
 158   return g_queue_pop_tail (stack);
 159 }
 160
 161 static void
 162 local_latency_query_stack_push (struct LatencyQueryTableValue *value)
 163 {
 164   GQueue *stack = local_latency_query_stack_get ();
 165   g_queue_push_tail (stack, value);
 166 }
 167
 168 /* hooks */
 169
 170 static void
 171 log_latency (const GstStructure * data, GstElement * sink_parent,
 172     GstPad * sink_pad, guint64 sink_ts)
 173 {
 174   guint64 src_ts;
 175   const char *src, *element_src, *id_element_src;
 176   const GValue *value;
 177   gchar *sink, *element_sink, *id_element_sink;
 178
 179   value = gst_structure_id_get_value (data, latency_probe_ts);
 180   src_ts = g_value_get_uint64 (value);
 181
 182   value = gst_structure_id_get_value (data, latency_probe_pad);
 183   src = g_value_get_string (value);
 184
 185   value = gst_structure_id_get_value (data, latency_probe_element);
 186   element_src = g_value_get_string (value);
 187
 188   value = gst_structure_id_get_value (data, latency_probe_element_id);
 189   id_element_src = g_value_get_string (value);
 190
 191   id_element_sink = g_strdup_printf ("%p", sink_parent);
 192   element_sink = gst_element_get_name (sink_parent);
 193   sink = gst_pad_get_name (sink_pad);
 194   gst_tracer_record_log (tr_latency, id_element_src, element_src, src,
 195       id_element_sink, element_sink, sink, GST_CLOCK_DIFF (src_ts, sink_ts),
 196       sink_ts);
 197   g_free (sink);
 198   g_free (element_sink);
 199   g_free (id_element_sink);
 200 }
 201
 202 static void
 203 log_element_latency (const GstStructure * data, GstElement * parent,
 204     GstPad * pad, guint64 sink_ts)
 205 {
 206   guint64 src_ts;
 207   gchar *pad_name, *element_name, *element_id;
 208   const GValue *value;
 209
 210   element_id = g_strdup_printf ("%p", parent);
 211   element_name = gst_element_get_name (parent);
 212   pad_name = gst_pad_get_name (pad);
 213
 214   /* TODO filtering */
 215
 216   value = gst_structure_id_get_value (data, latency_probe_ts);
 217   src_ts = g_value_get_uint64 (value);
 218
 219   gst_tracer_record_log (tr_element_latency, element_id, element_name, pad_name,
 220       GST_CLOCK_DIFF (src_ts, sink_ts), sink_ts);
 221
 222   g_free (pad_name);
 223   g_free (element_name);
 224   g_free (element_id);
 225 }
 226
 227 static void
 228 send_latency_probe (GstLatencyTracer * self, GstElement * parent, GstPad * pad,
 229     guint64 ts)
 230 {
 231   GstPad *peer_pad = GST_PAD_PEER (pad);
 232   GstElement *peer_parent = get_real_pad_parent (peer_pad);
 233
 234   /* allow for non-parented pads to send latency probes as used in e.g.
 235    * rtspsrc for TCP connections */
 236   if (peer_pad && (!parent || (!GST_IS_BIN (parent)))) {
 237     gchar *pad_name, *element_name, *element_id;
 238     GstEvent *latency_probe;
 239
 240     if (self->flags & GST_LATENCY_TRACER_FLAG_PIPELINE &&
 241         GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) {
 242       element_id = g_strdup_printf ("%p", parent);
 243       element_name = gst_element_get_name (parent);
 244       pad_name = gst_pad_get_name (pad);
 245
 246       latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
 247           gst_structure_new_id (latency_probe_id,
 248               latency_probe_element_id, G_TYPE_STRING, element_id,
 249               latency_probe_element, G_TYPE_STRING, element_name,
 250               latency_probe_pad, G_TYPE_STRING, pad_name,
 251               latency_probe_ts, G_TYPE_UINT64, ts, NULL));
 252
 253       GST_DEBUG ("%s_%s: Sending latency event %p", GST_DEBUG_PAD_NAME (pad),
 254           latency_probe);
 255
 256       g_free (pad_name);
 257       g_free (element_name);
 258       g_free (element_id);
 259       gst_pad_push_event (pad, latency_probe);
 260     }
 261
 262     if (self->flags & GST_LATENCY_TRACER_FLAG_ELEMENT) {
 263       element_id = g_strdup_printf ("%p", peer_parent);
 264       element_name = gst_element_get_name (peer_parent);
 265       pad_name = gst_pad_get_name (peer_pad);
 266
 267       latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
 268           gst_structure_new_id (sub_latency_probe_id,
 269               latency_probe_element_id, G_TYPE_STRING, element_id,
 270               latency_probe_element, G_TYPE_STRING, element_name,
 271               latency_probe_pad, G_TYPE_STRING, pad_name,
 272               latency_probe_ts, G_TYPE_UINT64, ts, NULL));
 273
 274       GST_DEBUG ("%s_%s: Sending sub-latency event %p",
 275           GST_DEBUG_PAD_NAME (pad), latency_probe);
 276
 277       gst_pad_push_event (pad, latency_probe);
 278       g_free (pad_name);
 279       g_free (element_name);
 280       g_free (element_id);
 281     }
 282   }
 283 }
 284
 285 static void
 286 calculate_latency (GstElement * parent, GstPad * pad, guint64 ts)
 287 {
 288   GstElement *peer_parent = get_real_pad_parent (GST_PAD_PEER (pad));
 289
 290   if (parent && (!GST_IS_BIN (parent)) &&
 291       (!GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE))) {
 292     GstEvent *ev;
 293
 294     /* FIXME unsafe use of peer */
 295     if (GST_OBJECT_FLAG_IS_SET (peer_parent, GST_ELEMENT_FLAG_SINK)) {
 296       ev = g_object_get_qdata ((GObject *) pad, latency_probe_id);
 297       GST_DEBUG ("%s_%s: Should log full lantency now (event %p)",
 298           GST_DEBUG_PAD_NAME (pad), ev);
 299       if (ev) {
 300         log_latency (gst_event_get_structure (ev), peer_parent,
 301             GST_PAD_PEER (pad), ts);
 302         g_object_set_qdata ((GObject *) pad, latency_probe_id, NULL);
 303       }
 304     }
 305
 306     ev = g_object_get_qdata ((GObject *) pad, sub_latency_probe_id);
 307     GST_DEBUG ("%s_%s: Should log sub lantency now (event %p)",
 308         GST_DEBUG_PAD_NAME (pad), ev);
 309     if (ev) {
 310       log_element_latency (gst_event_get_structure (ev), parent, pad, ts);
 311       g_object_set_qdata ((GObject *) pad, sub_latency_probe_id, NULL);
 312     }
 313   }
 314 }
 315
 316 static void
 317 do_push_buffer_pre (GstTracer * tracer, guint64 ts, GstPad * pad)
 318 {
 319   GstLatencyTracer *self = (GstLatencyTracer *) tracer;
 320   GstElement *parent = get_real_pad_parent (pad);
 321
 322   send_latency_probe (self, parent, pad, ts);
 323   calculate_latency (parent, pad, ts);
 324 }
 325
 326 static void
 327 do_pull_range_pre (GstTracer * tracer, guint64 ts, GstPad * pad)
 328 {
 329   GstLatencyTracer *self = (GstLatencyTracer *) tracer;
 330   GstPad *peer_pad = GST_PAD_PEER (pad);
 331   GstElement *parent = get_real_pad_parent (peer_pad);
 332
 333   send_latency_probe (self, parent, peer_pad, ts);
 334 }
 335
 336 static void
 337 do_pull_range_post (GstTracer * self, guint64 ts, GstPad * pad)
 338 {
 339   GstElement *parent = get_real_pad_parent (pad);
 340
 341   calculate_latency (parent, pad, ts);
 342 }
 343
 344 static GstPadProbeReturn
 345 do_drop_sub_latency_event (GstPad * pad, GstPadProbeInfo * info,
 346     gpointer user_data)
 347 {
 348   GstEvent *ev = info->data;
 349   GstPadProbeReturn ret = GST_PAD_PROBE_OK;
 350
 351   if (GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
 352     const GstStructure *data = gst_event_get_structure (ev);
 353
 354     if (gst_structure_get_name_id (data) == sub_latency_probe_id) {
 355       /* FIXME unsafe peer pad usage */
 356       GstPad *peer_pad = GST_PAD_PEER (pad);
 357       GstElement *peer_parent = get_real_pad_parent (peer_pad);
 358       const GValue *value;
 359       gchar *element_id = g_strdup_printf ("%p", peer_parent);
 360       gchar *pad_name = gst_pad_get_name (peer_pad);
 361       const gchar *value_element_id, *value_pad_name;
 362
 363       /* Get the element id, element name and pad name from data */
 364       value = gst_structure_id_get_value (data, latency_probe_element_id);
 365       value_element_id = g_value_get_string (value);
 366       value = gst_structure_id_get_value (data, latency_probe_pad);
 367       value_pad_name = g_value_get_string (value);
 368
 369       if (!g_str_equal (value_element_id, element_id) ||
 370           !g_str_equal (value_pad_name, pad_name)) {
 371         GST_DEBUG ("%s_%s: Dropping sub-latency event",
 372             GST_DEBUG_PAD_NAME (pad));
 373         ret = GST_PAD_PROBE_DROP;
 374       }
 375
 376       g_free (pad_name);
 377       g_free (element_id);
 378     }
 379   }
 380
 381   return ret;
 382 }
 383
 384 static void
 385 do_push_event_pre (GstTracer * self, guint64 ts, GstPad * pad, GstEvent * ev)
 386 {
 387   GstElement *parent = get_real_pad_parent (pad);
 388   GstPad *peer_pad = GST_PAD_PEER (pad);
 389   GstElement *peer_parent = get_real_pad_parent (peer_pad);
 390
 391   if (parent && (!GST_IS_BIN (parent)) &&
 392       (!GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) &&
 393       GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
 394     const GstStructure *data = gst_event_get_structure (ev);
 395
 396     /* if not set yet, add a pad probe that prevents sub-latency event from
 397      * flowing further */
 398     if (gst_structure_get_name_id (data) == latency_probe_id) {
 399
 400       if (!g_object_get_qdata ((GObject *) pad, drop_sub_latency_quark)) {
 401         GST_DEBUG ("%s_%s: Adding pad probe to drop sub-latency event",
 402             GST_DEBUG_PAD_NAME (pad));
 403         gst_pad_add_probe (pad, GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM,
 404             do_drop_sub_latency_event, NULL, NULL);
 405         g_object_set_qdata ((GObject *) pad, drop_sub_latency_quark,
 406             (gpointer) 1);
 407       }
 408
 409       /* FIXME unsafe peer access */
 410       if (GST_OBJECT_FLAG_IS_SET (peer_parent, GST_ELEMENT_FLAG_SINK)) {
 411         /* store event so that we can calculate latency when the buffer that
 412          * follows has been processed */
 413         g_object_set_qdata_full ((GObject *) pad, latency_probe_id,
 414             gst_event_ref (ev), (GDestroyNotify) gst_event_unref);
 415       }
 416     }
 417
 418     if (gst_structure_get_name_id (data) == sub_latency_probe_id) {
 419       const GValue *value;
 420       gchar *element_id = g_strdup_printf ("%p", peer_parent);
 421       gchar *pad_name = gst_pad_get_name (peer_pad);
 422       const gchar *value_element_id, *value_pad_name;
 423
 424       /* Get the element id, element name and pad name from data */
 425       value = gst_structure_id_get_value (data, latency_probe_element_id);
 426       value_element_id = g_value_get_string (value);
 427       value = gst_structure_id_get_value (data, latency_probe_pad);
 428       value_pad_name = g_value_get_string (value);
 429
 430       if (!g_str_equal (value_element_id, element_id) ||
 431           !g_str_equal (value_pad_name, pad_name)) {
 432         GST_DEBUG ("%s_%s: Storing sub-latency event",
 433             GST_DEBUG_PAD_NAME (pad));
 434         g_object_set_qdata_full ((GObject *) pad, sub_latency_probe_id,
 435             gst_event_ref (ev), (GDestroyNotify) gst_event_unref);
 436       }
 437
 438       g_free (pad_name);
 439       g_free (element_id);
 440     }
 441   }
 442 }
 443
 444 static void
 445 do_query_post (GstLatencyTracer * tracer, GstClockTime ts, GstPad * pad,
 446     GstQuery * query, gboolean res)
 447 {
 448   /* Only check for latency queries if flag is enabled */
 449   if ((tracer->flags & GST_LATENCY_TRACER_FLAG_REPORTED_ELEMENT) &&
 450       (GST_QUERY_TYPE (query) == GST_QUERY_LATENCY)) {
 451     gboolean live;
 452     guint64 min = 0, max = 0, min_prev = 0, max_prev = 0;
 453     gchar *element_name, *element_id;
 454     struct LatencyQueryTableValue *value;
 455     GstElement *element = get_real_pad_parent (pad);
 456     GstElement *peer_element = get_real_pad_parent (GST_PAD_PEER (pad));
 457
 458     /* Parse the query */
 459     gst_query_parse_latency (query, &live, &min, &max);
 460
 461     /* Pop from stack */
 462     value = local_latency_query_stack_pop ();
 463     while (value && value->peer_element == element) {
 464       min_prev = MAX (value->min, min_prev);
 465       max_prev = MAX (value->max, max_prev);
 466       value = local_latency_query_stack_pop ();
 467     }
 468
 469     /* Push to stack */
 470     value = g_new0 (struct LatencyQueryTableValue, 1);
 471     value->peer_element = gst_object_ref (peer_element);
 472     value->min = min;
 473     value->max = max;
 474     local_latency_query_stack_push (value);
 475
 476     /* Get the pad name */
 477     element_id = g_strdup_printf ("%p", element);
 478     element_name = gst_element_get_name (element);
 479
 480     /* Log reported latency */
 481     gst_tracer_record_log (tr_element_reported_latency, element_id,
 482         element_name, live, GST_CLOCK_DIFF (min_prev, min),
 483         GST_CLOCK_DIFF (max_prev, max), ts);
 484
 485     /* Clean up */
 486     g_free (element_name);
 487     g_free (element_id);
 488   }
 489 }
 490
 491 /* tracer class */
 492
 493 static void
 494 gst_latency_tracer_constructed (GObject * object)
 495 {
 496   GstLatencyTracer *self = GST_LATENCY_TRACER (object);
 497   gchar *params, *tmp;
 498   GstStructure *params_struct = NULL;
 499
 500   g_object_get (self, "params", &params, NULL);
 501
 502   if (!params)
 503     return;
 504
 505   tmp = g_strdup_printf ("latency,%s", params);
 506   params_struct = gst_structure_from_string (tmp, NULL);
 507   g_free (tmp);
 508
 509   /* Read the flags if available */
 510   if (params_struct) {
 511     const gchar *flags = gst_structure_get_string (params_struct, "flags");
 512
 513     self->flags = 0;
 514
 515     if (flags) {
 516       GStrv split = g_strsplit (flags, "+", -1);
 517       gint i;
 518
 519       for (i = 0; split[i]; i++) {
 520         if (g_str_equal (split[i], "pipeline"))
 521           self->flags |= GST_LATENCY_TRACER_FLAG_PIPELINE;
 522         else if (g_str_equal (split[i], "element"))
 523           self->flags |= GST_LATENCY_TRACER_FLAG_ELEMENT;
 524         else if (g_str_equal (split[i], "reported"))
 525           self->flags |= GST_LATENCY_TRACER_FLAG_REPORTED_ELEMENT;
 526         else
 527           GST_WARNING ("Invalid latency tracer flags %s", split[i]);
 528       }
 529
 530       g_strfreev (split);
 531     }
 532   }
 533
 534   g_free (params);
 535 }
 536
 537 static void
 538 gst_latency_tracer_class_init (GstLatencyTracerClass * klass)
 539 {
 540   GObjectClass *gobject_class = G_OBJECT_CLASS (klass);
 541
 542   gobject_class->constructed = gst_latency_tracer_constructed;
 543
 544   latency_probe_id = g_quark_from_static_string ("latency_probe.id");
 545   sub_latency_probe_id = g_quark_from_static_string ("sub_latency_probe.id");
 546   latency_probe_pad = g_quark_from_static_string ("latency_probe.pad");
 547   latency_probe_element = g_quark_from_static_string ("latency_probe.element");
 548   latency_probe_element_id =
 549       g_quark_from_static_string ("latency_probe.element_id");
 550   latency_probe_ts = g_quark_from_static_string ("latency_probe.ts");
 551   drop_sub_latency_quark =
 552       g_quark_from_static_string ("drop_sub_latency.quark");
 553
 554   /* announce trace formats */
 555   /* *INDENT-OFF* */
 556   tr_latency = gst_tracer_record_new ("latency.class",
 557       "src-element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 558           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 559           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 560           GST_TRACER_VALUE_SCOPE_ELEMENT,
 561           NULL),
 562       "src-element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 563           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 564           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 565           GST_TRACER_VALUE_SCOPE_ELEMENT,
 566           NULL),
 567       "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 568           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 569           "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
 570           NULL),
 571       "sink-element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 572           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 573           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 574           GST_TRACER_VALUE_SCOPE_ELEMENT,
 575           NULL),
 576       "sink-element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 577           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 578           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 579           GST_TRACER_VALUE_SCOPE_ELEMENT,
 580           NULL),
 581       "sink", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 582           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 583           "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
 584           NULL),
 585       "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 586           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 587           "description", G_TYPE_STRING,
 588               "time it took for the buffer to go from src to sink ns",
 589           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 590           "max", G_TYPE_UINT64, G_MAXUINT64,
 591           NULL),
 592       "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 593           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 594           "description", G_TYPE_STRING, "ts when the latency has been logged",
 595           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 596           "max", G_TYPE_UINT64, G_MAXUINT64,
 597           NULL),
 598       NULL);
 599
 600   tr_element_latency = gst_tracer_record_new ("element-latency.class",
 601       "element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 602           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 603           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 604           GST_TRACER_VALUE_SCOPE_ELEMENT,
 605           NULL),
 606       "element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 607           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 608           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 609           GST_TRACER_VALUE_SCOPE_ELEMENT,
 610           NULL),
 611       "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 612           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 613           "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
 614           NULL),
 615       "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 616           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 617           "description", G_TYPE_STRING,
 618               "time it took for the buffer to go from src to sink ns",
 619           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 620           "max", G_TYPE_UINT64, G_MAXUINT64,
 621           NULL),
 622       "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 623           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 624           "description", G_TYPE_STRING, "ts when the latency has been logged",
 625           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 626           "max", G_TYPE_UINT64, G_MAXUINT64,
 627           NULL),
 628       NULL);
 629
 630
 631   tr_element_reported_latency = gst_tracer_record_new (
 632       "element-reported-latency.class",
 633       "element-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 634           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 635           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 636           GST_TRACER_VALUE_SCOPE_ELEMENT,
 637           NULL),
 638       "element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 639           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 640           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 641           GST_TRACER_VALUE_SCOPE_ELEMENT,
 642           NULL),
 643       "live", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 644           "type", G_TYPE_GTYPE, G_TYPE_BOOLEAN,
 645           "description", G_TYPE_STRING,
 646               "wether the it is a live stream or not",
 647           NULL),
 648       "min", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 649           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 650           "description", G_TYPE_STRING,
 651               "the minimum reported latency",
 652           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 653           "max", G_TYPE_UINT64, G_MAXUINT64,
 654           NULL),
 655       "max", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 656           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 657           "description", G_TYPE_STRING, "the maximum reported latency",
 658           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 659           "max", G_TYPE_UINT64, G_MAXUINT64,
 660           NULL),
 661       "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 662           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 663           "description", G_TYPE_STRING, "ts when the latency has been reported",
 664           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 665           "max", G_TYPE_UINT64, G_MAXUINT64,
 666           NULL),
 667       NULL);
 668   /* *INDENT-ON* */
 669
 670   GST_OBJECT_FLAG_SET (tr_latency, GST_OBJECT_FLAG_MAY_BE_LEAKED);
 671   GST_OBJECT_FLAG_SET (tr_element_latency, GST_OBJECT_FLAG_MAY_BE_LEAKED);
 672   GST_OBJECT_FLAG_SET (tr_element_reported_latency,
 673       GST_OBJECT_FLAG_MAY_BE_LEAKED);
 674 }
 675
 676 static void
 677 gst_latency_tracer_init (GstLatencyTracer * self)
 678 {
 679   GstTracer *tracer = GST_TRACER (self);
 680
 681   /* only trace pipeline latency by default */
 682   self->flags = GST_LATENCY_TRACER_FLAG_PIPELINE;
 683
 684   /* in push mode, pre/post will be called before/after the peer chain
 685    * function has been called. For this reaosn, we only use -pre to avoid
 686    * accounting for the processing time of the peer element (the sink) */
 687   gst_tracing_register_hook (tracer, "pad-push-pre",
 688       G_CALLBACK (do_push_buffer_pre));
 689   gst_tracing_register_hook (tracer, "pad-push-list-pre",
 690       G_CALLBACK (do_push_buffer_pre));
 691
 692   /* while in pull mode, pre/post will happen before and after the upstream
 693    * pull_range call is made, so it already only account for the upstream
 694    * processing time. As a side effect, in pull mode, we can measure the
 695    * source processing latency, while in push mode, we can't */
 696   gst_tracing_register_hook (tracer, "pad-pull-range-pre",
 697       G_CALLBACK (do_pull_range_pre));
 698   gst_tracing_register_hook (tracer, "pad-pull-range-post",
 699       G_CALLBACK (do_pull_range_post));
 700
 701   gst_tracing_register_hook (tracer, "pad-push-event-pre",
 702       G_CALLBACK (do_push_event_pre));
 703
 704   /* Add pad query post hook to get the reported per-element latency */
 705   gst_tracing_register_hook (tracer, "pad-query-post",
 706       G_CALLBACK (do_query_post));
 707 }