2 * Copyright (C) 2013 Stefan Sauer <ensonic@users.sf.net>
4 * gstlatency.c: tracing module that logs processing latency stats
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.
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.
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.
23 * @short_description: log processing latency stats
25 * A tracing module that determines src-to-sink latencies by injecting custom
26 * events at sources and process them at sinks.
28 /* TODO(ensonic): if there are two sources feeding into a mixer/muxer and later
29 * we fan-out with tee and have two sinks, each sink would get all two events,
30 * the later event would overwrite the former. Unfortunately when the buffer
31 * arrives on the sink we don't know to which event it correlates. Better would
32 * be to use the buffer meta in 1.0 instead of the event. Or we track a min/max
40 #include "gstlatency.h"
41 #include <gst/gsttracerrecord.h>
43 GST_DEBUG_CATEGORY_STATIC (gst_latency_debug);
44 #define GST_CAT_DEFAULT gst_latency_debug
47 GST_DEBUG_CATEGORY_INIT (gst_latency_debug, "latency", 0, "latency tracer");
48 #define gst_latency_tracer_parent_class parent_class
49 G_DEFINE_TYPE_WITH_CODE (GstLatencyTracer, gst_latency_tracer, GST_TYPE_TRACER,
52 static GQuark latency_probe_id;
53 static GQuark latency_probe_pad;
54 static GQuark latency_probe_ts;
56 static GstTracerRecord *tr_latency;
61 * Get the element/bin owning the pad.
67 * out: the element that contains the peer of the proxy
70 * out: the bin owning the ghostpad
72 /* TODO(ensonic): gst_pad_get_parent_element() would not work here, should we
73 * add this as new api, e.g. gst_pad_find_parent_element();
76 get_real_pad_parent (GstPad * pad)
83 parent = GST_OBJECT_PARENT (pad);
85 /* if parent of pad is a ghost-pad, then pad is a proxy_pad */
86 if (parent && GST_IS_GHOST_PAD (parent)) {
87 pad = GST_PAD_CAST (parent);
88 parent = GST_OBJECT_PARENT (pad);
90 return GST_ELEMENT_CAST (parent);
96 log_latency (const GstStructure * data, GstPad * sink_pad, guint64 sink_ts)
102 gst_structure_id_get (data,
103 latency_probe_pad, GST_TYPE_PAD, &src_pad,
104 latency_probe_ts, G_TYPE_UINT64, &src_ts, NULL);
106 src = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (src_pad));
107 sink = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (sink_pad));
109 gst_tracer_record_log (tr_latency, src, sink,
110 GST_CLOCK_DIFF (src_ts, sink_ts));
116 send_latency_probe (GstElement * parent, GstPad * pad, guint64 ts)
118 if (parent && (!GST_IS_BIN (parent)) &&
119 GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) {
120 GstEvent *latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
121 gst_structure_new_id (latency_probe_id,
122 latency_probe_pad, GST_TYPE_PAD, pad,
123 latency_probe_ts, G_TYPE_UINT64, ts,
125 gst_pad_push_event (pad, latency_probe);
130 do_push_buffer_pre (GstTracer * self, guint64 ts, GstPad * pad)
132 GstElement *parent = get_real_pad_parent (pad);
134 send_latency_probe (parent, pad, ts);
138 do_pull_range_pre (GstTracer * self, guint64 ts, GstPad * pad)
140 GstPad *peer_pad = GST_PAD_PEER (pad);
141 GstElement *parent = get_real_pad_parent (peer_pad);
143 send_latency_probe (parent, peer_pad, ts);
147 calculate_latency (GstElement * parent, GstPad * pad, guint64 ts)
149 if (parent && (!GST_IS_BIN (parent)) &&
150 GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SINK)) {
151 GstEvent *ev = g_object_get_qdata ((GObject *) pad, latency_probe_id);
153 log_latency (gst_event_get_structure (ev), pad, ts);
154 gst_event_unref (ev);
159 do_push_buffer_post (GstTracer * self, guint64 ts, GstPad * pad)
161 GstPad *peer_pad = GST_PAD_PEER (pad);
162 GstElement *parent = get_real_pad_parent (peer_pad);
164 calculate_latency (parent, peer_pad, ts);
168 do_pull_range_post (GstTracer * self, guint64 ts, GstPad * pad)
170 GstElement *parent = get_real_pad_parent (pad);
172 calculate_latency (parent, pad, ts);
176 do_push_event_pre (GstTracer * self, guint64 ts, GstPad * pad, GstEvent * ev)
178 GstPad *peer_pad = GST_PAD_PEER (pad);
179 GstElement *parent = get_real_pad_parent (peer_pad);
181 if (parent && (!GST_IS_BIN (parent)) &&
182 GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SINK)) {
183 if (GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
184 const GstStructure *data = gst_event_get_structure (ev);
186 if (gst_structure_get_name_id (data) == latency_probe_id) {
187 /* store event and calculate latency when the buffer that follows
188 * has been processed */
189 g_object_set_qdata ((GObject *) peer_pad, latency_probe_id,
199 gst_latency_tracer_class_init (GstLatencyTracerClass * klass)
201 latency_probe_id = g_quark_from_static_string ("latency_probe.id");
202 latency_probe_pad = g_quark_from_static_string ("latency_probe.pad");
203 latency_probe_ts = g_quark_from_static_string ("latency_probe.ts");
205 /* announce trace formats */
207 tr_latency = gst_tracer_record_new (gst_structure_new ("latency.class",
208 "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
209 "type", G_TYPE_GTYPE, G_TYPE_STRING,
210 "related-to", G_TYPE_STRING, "pad", /* TODO: use genum */
212 "sink", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
213 "type", G_TYPE_GTYPE, G_TYPE_STRING,
214 "related-to", G_TYPE_STRING, "pad", /* TODO: use genum */
216 "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
217 "type", G_TYPE_GTYPE, G_TYPE_UINT64,
218 "description", G_TYPE_STRING,
219 "time it took for the buffer to go from src to sink ns",
220 "flags", G_TYPE_STRING, "aggregated", /* TODO: use gflags */
221 "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
222 "max", G_TYPE_UINT64, G_MAXUINT64,
229 gst_latency_tracer_init (GstLatencyTracer * self)
231 GstTracer *tracer = GST_TRACER (self);
232 gst_tracing_register_hook (tracer, "pad-push-pre",
233 G_CALLBACK (do_push_buffer_pre));
234 gst_tracing_register_hook (tracer, "pad-push-list-pre",
235 G_CALLBACK (do_push_buffer_pre));
236 gst_tracing_register_hook (tracer, "pad-push-post",
237 G_CALLBACK (do_push_buffer_post));
238 gst_tracing_register_hook (tracer, "pad-push-list-post",
239 G_CALLBACK (do_push_buffer_post));
240 gst_tracing_register_hook (tracer, "pad-pull-range-pre",
241 G_CALLBACK (do_pull_range_pre));
242 gst_tracing_register_hook (tracer, "pad-pull-range-post",
243 G_CALLBACK (do_pull_range_post));
244 gst_tracing_register_hook (tracer, "pad-push-event-pre",
245 G_CALLBACK (do_push_event_pre));