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_ts;
  64 static GQuark drop_sub_latency_quark;
  65
  66 static GstTracerRecord *tr_latency;
  67 static GstTracerRecord *tr_element_latency;
  68 static GstTracerRecord *tr_element_reported_latency;
  69
  70 /* The private stack for each thread */
  71 static GPrivate latency_query_stack =
  72 G_PRIVATE_INIT (latency_query_stack_destroy);
  73
  74 struct LatencyQueryTableValue
  75 {
  76   GstElement *peer_element;
  77   guint64 min;
  78   guint64 max;
  79 };
  80
  81 /* data helpers */
  82
  83 /*
  84  * Get the element/bin owning the pad.
  85  *
  86  * in: a normal pad
  87  * out: the element
  88  *
  89  * in: a proxy pad
  90  * out: the element that contains the peer of the proxy
  91  *
  92  * in: a ghost pad
  93  * out: the bin owning the ghostpad
  94  */
  95 /* TODO(ensonic): gst_pad_get_parent_element() would not work here, should we
  96  * add this as new api, e.g. gst_pad_find_parent_element();
  97  */
  98 static GstElement *
  99 get_real_pad_parent (GstPad * pad)
 100 {
 101   GstObject *parent;
 102
 103   if (!pad)
 104     return NULL;
 105
 106   parent = GST_OBJECT_PARENT (pad);
 107
 108   /* if parent of pad is a ghost-pad, then pad is a proxy_pad */
 109   if (parent && GST_IS_GHOST_PAD (parent)) {
 110     pad = GST_PAD_CAST (parent);
 111     parent = GST_OBJECT_PARENT (pad);
 112   }
 113   return GST_ELEMENT_CAST (parent);
 114 }
 115
 116 static void
 117 latency_query_table_value_destroy (gpointer data)
 118 {
 119   struct LatencyQueryTableValue *v = data;
 120
 121   /* Unref the element */
 122   if (v->peer_element) {
 123     gst_object_unref (v->peer_element);
 124     v->peer_element = NULL;
 125   }
 126
 127   /* Destroy the structure */
 128   g_free (v);
 129 }
 130
 131 static void
 132 latency_query_stack_destroy (gpointer data)
 133 {
 134   GQueue *queue = data;
 135   g_queue_free_full (queue, latency_query_table_value_destroy);
 136 }
 137
 138 static GQueue *
 139 local_latency_query_stack_get (void)
 140 {
 141   /* Make sure the stack exists */
 142   GQueue *stack = g_private_get (&latency_query_stack);
 143   if (!stack) {
 144     g_private_set (&latency_query_stack, g_queue_new ());
 145     stack = g_private_get (&latency_query_stack);
 146   }
 147
 148   g_assert (stack);
 149   return stack;
 150 }
 151
 152 static struct LatencyQueryTableValue *
 153 local_latency_query_stack_pop (void)
 154 {
 155   GQueue *stack = local_latency_query_stack_get ();
 156   return g_queue_pop_tail (stack);
 157 }
 158
 159 static void
 160 local_latency_query_stack_push (struct LatencyQueryTableValue *value)
 161 {
 162   GQueue *stack = local_latency_query_stack_get ();
 163   g_queue_push_tail (stack, value);
 164 }
 165
 166 /* hooks */
 167
 168 static void
 169 log_latency (const GstStructure * data, GstPad * sink_pad, guint64 sink_ts)
 170 {
 171   guint64 src_ts;
 172   const char *src;
 173   const GValue *value;
 174   gchar *sink;
 175
 176   value = gst_structure_id_get_value (data, latency_probe_ts);
 177   src_ts = g_value_get_uint64 (value);
 178
 179   value = gst_structure_id_get_value (data, latency_probe_pad);
 180   src = g_value_get_string (value);
 181
 182   sink = g_strdup_printf ("%s_%s",
 183       GST_DEBUG_PAD_NAME (GST_PAD_PEER (sink_pad)));
 184   gst_tracer_record_log (tr_latency, src, sink,
 185       GST_CLOCK_DIFF (src_ts, sink_ts), sink_ts);
 186   g_free (sink);
 187 }
 188
 189 static void
 190 log_element_latency (const GstStructure * data, GstPad * pad, guint64 sink_ts)
 191 {
 192   guint64 src_ts;
 193   gchar *pad_name;
 194   const GValue *value;
 195
 196   pad_name = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (pad));
 197
 198   /* TODO filtering */
 199
 200   value = gst_structure_id_get_value (data, latency_probe_ts);
 201   src_ts = g_value_get_uint64 (value);
 202
 203   gst_tracer_record_log (tr_element_latency, pad_name,
 204       GST_CLOCK_DIFF (src_ts, sink_ts), sink_ts);
 205
 206   g_free (pad_name);
 207 }
 208
 209 static void
 210 send_latency_probe (GstLatencyTracer * self, GstElement * parent, GstPad * pad,
 211     guint64 ts)
 212 {
 213   GstPad *peer_pad = GST_PAD_PEER (pad);
 214
 215   /* allow for non-parented pads to send latency probes as used in e.g.
 216    * rtspsrc for TCP connections */
 217   if (peer_pad && (!parent || (!GST_IS_BIN (parent)))) {
 218     gchar *pad_name;
 219     GstEvent *latency_probe;
 220
 221     if (self->flags & GST_LATENCY_TRACER_FLAG_PIPELINE &&
 222         GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) {
 223       pad_name = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (pad));
 224
 225       GST_DEBUG ("%s: Sending latency event", pad_name);
 226
 227       latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
 228           gst_structure_new_id (latency_probe_id,
 229               latency_probe_pad, G_TYPE_STRING, pad_name,
 230               latency_probe_ts, G_TYPE_UINT64, ts, NULL));
 231       g_free (pad_name);
 232       gst_pad_push_event (pad, latency_probe);
 233     }
 234
 235     if (self->flags & GST_LATENCY_TRACER_FLAG_ELEMENT) {
 236       GST_DEBUG ("%s_%s: Sending sub-latency event", GST_DEBUG_PAD_NAME (pad));
 237
 238       pad_name = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (peer_pad));
 239       latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
 240           gst_structure_new_id (sub_latency_probe_id,
 241               latency_probe_pad, G_TYPE_STRING, pad_name,
 242               latency_probe_ts, G_TYPE_UINT64, ts, NULL));
 243       gst_pad_push_event (pad, latency_probe);
 244       g_free (pad_name);
 245     }
 246   }
 247 }
 248
 249 static void
 250 calculate_latency (GstElement * parent, GstPad * pad, guint64 ts)
 251 {
 252   GstElement *peer_parent = get_real_pad_parent (GST_PAD_PEER (pad));
 253
 254   if (parent && (!GST_IS_BIN (parent)) &&
 255       (!GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE))) {
 256     GstEvent *ev;
 257
 258     /* FIXME unsafe use of peer */
 259     if (GST_OBJECT_FLAG_IS_SET (peer_parent, GST_ELEMENT_FLAG_SINK)) {
 260       GST_DEBUG ("%s_%s: Should log full lantency now",
 261           GST_DEBUG_PAD_NAME (pad));
 262       ev = g_object_get_qdata ((GObject *) pad, latency_probe_id);
 263       if (ev) {
 264         g_object_set_qdata ((GObject *) pad, latency_probe_id, NULL);
 265         log_latency (gst_event_get_structure (ev), pad, ts);
 266         gst_event_unref (ev);
 267       }
 268     }
 269
 270     GST_DEBUG ("%s_%s: Should log sub lantency now", GST_DEBUG_PAD_NAME (pad));
 271     ev = g_object_get_qdata ((GObject *) pad, sub_latency_probe_id);
 272     if (ev) {
 273       g_object_set_qdata ((GObject *) pad, sub_latency_probe_id, NULL);
 274       log_element_latency (gst_event_get_structure (ev), pad, ts);
 275       gst_event_unref (ev);
 276     }
 277   }
 278 }
 279
 280 static void
 281 do_push_buffer_pre (GstTracer * tracer, guint64 ts, GstPad * pad)
 282 {
 283   GstLatencyTracer *self = (GstLatencyTracer *) tracer;
 284   GstElement *parent = get_real_pad_parent (pad);
 285
 286   send_latency_probe (self, parent, pad, ts);
 287   calculate_latency (parent, pad, ts);
 288 }
 289
 290 static void
 291 do_pull_range_pre (GstTracer * tracer, guint64 ts, GstPad * pad)
 292 {
 293   GstLatencyTracer *self = (GstLatencyTracer *) tracer;
 294   GstPad *peer_pad = GST_PAD_PEER (pad);
 295   GstElement *parent = get_real_pad_parent (peer_pad);
 296
 297   send_latency_probe (self, parent, peer_pad, ts);
 298 }
 299
 300 static void
 301 do_pull_range_post (GstTracer * self, guint64 ts, GstPad * pad)
 302 {
 303   GstElement *parent = get_real_pad_parent (pad);
 304
 305   calculate_latency (parent, pad, ts);
 306 }
 307
 308 static GstPadProbeReturn
 309 do_drop_sub_latency_event (GstPad * pad, GstPadProbeInfo * info,
 310     gpointer user_data)
 311 {
 312   GstEvent *ev = info->data;
 313   GstPadProbeReturn ret = GST_PAD_PROBE_OK;
 314
 315   if (GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
 316     const GstStructure *data = gst_event_get_structure (ev);
 317
 318     if (gst_structure_get_name_id (data) == sub_latency_probe_id) {
 319       const GValue *value;
 320       /* FIXME unsafe peer pad usage */
 321       gchar *pad_name = g_strdup_printf ("%s_%s",
 322           GST_DEBUG_PAD_NAME (GST_PAD_PEER (pad)));
 323
 324       value = gst_structure_id_get_value (data, latency_probe_pad);
 325       if (!g_str_equal (g_value_get_string (value), pad_name)) {
 326         GST_DEBUG ("%s: Dropping sub-latency event", pad_name);
 327         ret = GST_PAD_PROBE_DROP;
 328       }
 329
 330       g_free (pad_name);
 331     }
 332   }
 333
 334   return ret;
 335 }
 336
 337 static void
 338 do_push_event_pre (GstTracer * self, guint64 ts, GstPad * pad, GstEvent * ev)
 339 {
 340   GstElement *parent = get_real_pad_parent (pad);
 341   GstPad *peer_pad = GST_PAD_PEER (pad);
 342   GstElement *peer_parent = get_real_pad_parent (peer_pad);
 343
 344   if (parent && (!GST_IS_BIN (parent)) &&
 345       (!GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) &&
 346       GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
 347     const GstStructure *data = gst_event_get_structure (ev);
 348
 349     /* if not set yet, add a pad probe that prevents sub-latency event from
 350      * flowing further */
 351     if (gst_structure_get_name_id (data) == latency_probe_id) {
 352
 353       if (!g_object_get_qdata ((GObject *) pad, drop_sub_latency_quark)) {
 354         GST_DEBUG ("%s_%s: Adding pad probe to drop sub-latency event",
 355             GST_DEBUG_PAD_NAME (pad));
 356         gst_pad_add_probe (pad, GST_PAD_PROBE_TYPE_EVENT_DOWNSTREAM,
 357             do_drop_sub_latency_event, NULL, NULL);
 358         g_object_set_qdata ((GObject *) pad, drop_sub_latency_quark,
 359             (gpointer) 1);
 360       }
 361
 362       /* FIXME unsafe peer access */
 363       if (GST_OBJECT_FLAG_IS_SET (peer_parent, GST_ELEMENT_FLAG_SINK)) {
 364         GST_DEBUG ("%s_%s: Storing latency event", GST_DEBUG_PAD_NAME (pad));
 365
 366         /* store event so that we can calculate latency when the buffer that
 367          * follows has been processed */
 368         if (!g_object_get_qdata ((GObject *) pad, latency_probe_id))
 369           g_object_set_qdata ((GObject *) pad, latency_probe_id,
 370               gst_event_ref (ev));
 371       }
 372     }
 373
 374     if (gst_structure_get_name_id (data) == sub_latency_probe_id) {
 375       const GValue *value;
 376       gchar *pad_name = g_strdup_printf ("%s_%s",
 377           GST_DEBUG_PAD_NAME (peer_pad));
 378
 379       value = gst_structure_id_get_value (data, latency_probe_pad);
 380
 381       if (!g_str_equal (g_value_get_string (value), pad_name)) {
 382         GST_DEBUG ("%s: Storing sub-latency event", pad_name);
 383         if (!g_object_get_qdata ((GObject *) pad, sub_latency_probe_id))
 384           g_object_set_qdata ((GObject *) pad, sub_latency_probe_id,
 385               gst_event_ref (ev));
 386       }
 387
 388       g_free (pad_name);
 389     }
 390   }
 391 }
 392
 393 static void
 394 do_query_post (GstLatencyTracer * tracer, GstClockTime ts, GstPad * pad,
 395     GstQuery * query, gboolean res)
 396 {
 397   /* Only check for latency queries if flag is enabled */
 398   if ((tracer->flags & GST_LATENCY_TRACER_FLAG_REPORTED_ELEMENT) &&
 399       (GST_QUERY_TYPE (query) == GST_QUERY_LATENCY)) {
 400     gboolean live;
 401     guint64 min = 0, max = 0, min_prev = 0, max_prev = 0;
 402     gchar *element_name;
 403     struct LatencyQueryTableValue *value;
 404     GstElement *element = get_real_pad_parent (pad);
 405     GstElement *peer_element = get_real_pad_parent (GST_PAD_PEER (pad));
 406
 407     /* Parse the query */
 408     gst_query_parse_latency (query, &live, &min, &max);
 409
 410     /* Pop from stack */
 411     value = local_latency_query_stack_pop ();
 412     while (value && value->peer_element == element) {
 413       min_prev = MAX (value->min, min_prev);
 414       max_prev = MAX (value->max, max_prev);
 415       value = local_latency_query_stack_pop ();
 416     }
 417
 418     /* Push to stack */
 419     value = g_new0 (struct LatencyQueryTableValue, 1);
 420     value->peer_element = gst_object_ref (peer_element);
 421     value->min = min;
 422     value->max = max;
 423     local_latency_query_stack_push (value);
 424
 425     /* Get the pad name */
 426     element_name = gst_element_get_name (element);
 427
 428     /* Log reported latency */
 429     gst_tracer_record_log (tr_element_reported_latency, element_name, live,
 430         GST_CLOCK_DIFF (min_prev, min), GST_CLOCK_DIFF (max_prev, max), ts);
 431
 432     /* Clean up */
 433     g_free (element_name);
 434   }
 435 }
 436
 437 /* tracer class */
 438
 439 static void
 440 gst_latency_tracer_constructed (GObject * object)
 441 {
 442   GstLatencyTracer *self = GST_LATENCY_TRACER (object);
 443   gchar *params, *tmp;
 444   GstStructure *params_struct = NULL;
 445
 446   g_object_get (self, "params", &params, NULL);
 447
 448   if (!params)
 449     return;
 450
 451   tmp = g_strdup_printf ("latency,%s", params);
 452   params_struct = gst_structure_from_string (tmp, NULL);
 453   g_free (tmp);
 454
 455   /* Read the flags if available */
 456   if (params_struct) {
 457     const gchar *flags = gst_structure_get_string (params_struct, "flags");
 458
 459     self->flags = 0;
 460
 461     if (flags) {
 462       GStrv split = g_strsplit (flags, "+", -1);
 463       gint i;
 464
 465       for (i = 0; split[i]; i++) {
 466         if (g_str_equal (split[i], "pipeline"))
 467           self->flags |= GST_LATENCY_TRACER_FLAG_PIPELINE;
 468         else if (g_str_equal (split[i], "element"))
 469           self->flags |= GST_LATENCY_TRACER_FLAG_ELEMENT;
 470         else if (g_str_equal (split[i], "reported"))
 471           self->flags |= GST_LATENCY_TRACER_FLAG_REPORTED_ELEMENT;
 472         else
 473           GST_WARNING ("Invalid latency tracer flags %s", split[i]);
 474       }
 475
 476       g_strfreev (split);
 477     }
 478   }
 479
 480   g_free (params);
 481 }
 482
 483 static void
 484 gst_latency_tracer_class_init (GstLatencyTracerClass * klass)
 485 {
 486   GObjectClass *gobject_class = G_OBJECT_CLASS (klass);
 487
 488   gobject_class->constructed = gst_latency_tracer_constructed;
 489
 490   latency_probe_id = g_quark_from_static_string ("latency_probe.id");
 491   sub_latency_probe_id = g_quark_from_static_string ("sub_latency_probe.id");
 492   latency_probe_pad = g_quark_from_static_string ("latency_probe.pad");
 493   latency_probe_ts = g_quark_from_static_string ("latency_probe.ts");
 494   drop_sub_latency_quark =
 495       g_quark_from_static_string ("drop_sub_latency.quark");
 496
 497   /* announce trace formats */
 498   /* *INDENT-OFF* */
 499   tr_latency = gst_tracer_record_new ("latency.class",
 500       "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 501           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 502           "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
 503           NULL),
 504       "sink", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 505           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 506           "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
 507           NULL),
 508       "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 509           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 510           "description", G_TYPE_STRING,
 511               "time it took for the buffer to go from src to sink ns",
 512           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 513           "max", G_TYPE_UINT64, G_MAXUINT64,
 514           NULL),
 515       "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 516           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 517           "description", G_TYPE_STRING, "ts when the latency has been logged",
 518           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 519           "max", G_TYPE_UINT64, G_MAXUINT64,
 520           NULL),
 521       NULL);
 522
 523   tr_element_latency = gst_tracer_record_new ("element-latency.class",
 524       "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 525           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 526           "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
 527           NULL),
 528       "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 529           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 530           "description", G_TYPE_STRING,
 531               "time it took for the buffer to go from src to sink ns",
 532           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 533           "max", G_TYPE_UINT64, G_MAXUINT64,
 534           NULL),
 535       "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 536           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 537           "description", G_TYPE_STRING, "ts when the latency has been logged",
 538           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 539           "max", G_TYPE_UINT64, G_MAXUINT64,
 540           NULL),
 541       NULL);
 542
 543
 544   tr_element_reported_latency = gst_tracer_record_new (
 545       "element-reported-latency.class",
 546       "element", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
 547           "type", G_TYPE_GTYPE, G_TYPE_STRING,
 548           "related-to", GST_TYPE_TRACER_VALUE_SCOPE,
 549           GST_TRACER_VALUE_SCOPE_ELEMENT,
 550           NULL),
 551       "live", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 552           "type", G_TYPE_GTYPE, G_TYPE_BOOLEAN,
 553           "description", G_TYPE_STRING,
 554               "wether the it is a live stream or not",
 555           NULL),
 556       "min", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 557           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 558           "description", G_TYPE_STRING,
 559               "the minimum reported latency",
 560           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 561           "max", G_TYPE_UINT64, G_MAXUINT64,
 562           NULL),
 563       "max", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 564           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 565           "description", G_TYPE_STRING, "the maximum reported latency",
 566           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 567           "max", G_TYPE_UINT64, G_MAXUINT64,
 568           NULL),
 569       "ts", GST_TYPE_STRUCTURE, gst_structure_new ("value",
 570           "type", G_TYPE_GTYPE, G_TYPE_UINT64,
 571           "description", G_TYPE_STRING, "ts when the latency has been reported",
 572           "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
 573           "max", G_TYPE_UINT64, G_MAXUINT64,
 574           NULL),
 575       NULL);
 576   /* *INDENT-ON* */
 577 }
 578
 579 static void
 580 gst_latency_tracer_init (GstLatencyTracer * self)
 581 {
 582   GstTracer *tracer = GST_TRACER (self);
 583
 584   /* only trace pipeline latency by default */
 585   self->flags = GST_LATENCY_TRACER_FLAG_PIPELINE;
 586
 587   /* in push mode, pre/post will be called before/after the peer chain
 588    * function has been called. For this reaosn, we only use -pre to avoid
 589    * accounting for the processing time of the peer element (the sink) */
 590   gst_tracing_register_hook (tracer, "pad-push-pre",
 591       G_CALLBACK (do_push_buffer_pre));
 592   gst_tracing_register_hook (tracer, "pad-push-list-pre",
 593       G_CALLBACK (do_push_buffer_pre));
 594
 595   /* while in pull mode, pre/post will happen before and after the upstream
 596    * pull_range call is made, so it already only account for the upstream
 597    * processing time. As a side effect, in pull mode, we can measure the
 598    * source processing latency, while in push mode, we can't */
 599   gst_tracing_register_hook (tracer, "pad-pull-range-pre",
 600       G_CALLBACK (do_pull_range_pre));
 601   gst_tracing_register_hook (tracer, "pad-pull-range-post",
 602       G_CALLBACK (do_pull_range_post));
 603
 604   gst_tracing_register_hook (tracer, "pad-push-event-pre",
 605       G_CALLBACK (do_push_event_pre));
 606
 607   /* Add pad query post hook to get the reported per-element latency */
 608   gst_tracing_register_hook (tracer, "pad-query-post",
 609       G_CALLBACK (do_query_post));
 610 }