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"
42 GST_DEBUG_CATEGORY_STATIC (gst_latency_debug);
43 #define GST_CAT_DEFAULT gst_latency_debug
46 GST_DEBUG_CATEGORY_INIT (gst_latency_debug, "latency", 0, "latency tracer");
47 #define gst_latency_tracer_parent_class parent_class
48 G_DEFINE_TYPE_WITH_CODE (GstLatencyTracer, gst_latency_tracer, GST_TYPE_TRACER,
51 static GQuark latency_probe_id;
52 static GQuark latency_probe_pad;
53 static GQuark latency_probe_ts;
55 static GstTracerRecord *tr_latency;
60 * Get the element/bin owning the pad.
66 * out: the element that contains the peer of the proxy
69 * out: the bin owning the ghostpad
71 /* TODO(ensonic): gst_pad_get_parent_element() would not work here, should we
72 * add this as new api, e.g. gst_pad_find_parent_element();
75 get_real_pad_parent (GstPad * pad)
82 parent = GST_OBJECT_PARENT (pad);
84 /* if parent of pad is a ghost-pad, then pad is a proxy_pad */
85 if (parent && GST_IS_GHOST_PAD (parent)) {
86 pad = GST_PAD_CAST (parent);
87 parent = GST_OBJECT_PARENT (pad);
89 return GST_ELEMENT_CAST (parent);
95 log_latency (const GstStructure * data, GstPad * sink_pad, guint64 sink_ts)
101 gst_structure_id_get (data,
102 latency_probe_pad, GST_TYPE_PAD, &src_pad,
103 latency_probe_ts, G_TYPE_UINT64, &src_ts, NULL);
105 src = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (src_pad));
106 sink = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (sink_pad));
108 gst_tracer_record_log (tr_latency, src, sink,
109 GST_CLOCK_DIFF (src_ts, sink_ts));
115 send_latency_probe (GstElement * parent, GstPad * pad, guint64 ts)
117 if (parent && (!GST_IS_BIN (parent)) &&
118 GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SOURCE)) {
119 GstEvent *latency_probe = gst_event_new_custom (GST_EVENT_CUSTOM_DOWNSTREAM,
120 gst_structure_new_id (latency_probe_id,
121 latency_probe_pad, GST_TYPE_PAD, pad,
122 latency_probe_ts, G_TYPE_UINT64, ts,
124 gst_pad_push_event (pad, latency_probe);
129 do_push_buffer_pre (GstTracer * self, guint64 ts, GstPad * pad)
131 GstElement *parent = get_real_pad_parent (pad);
133 send_latency_probe (parent, pad, ts);
137 do_pull_range_pre (GstTracer * self, guint64 ts, GstPad * pad)
139 GstPad *peer_pad = GST_PAD_PEER (pad);
140 GstElement *parent = get_real_pad_parent (peer_pad);
142 send_latency_probe (parent, peer_pad, ts);
146 calculate_latency (GstElement * parent, GstPad * pad, guint64 ts)
148 if (parent && (!GST_IS_BIN (parent)) &&
149 GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SINK)) {
150 GstEvent *ev = g_object_get_qdata ((GObject *) pad, latency_probe_id);
153 g_object_set_qdata ((GObject *) pad, latency_probe_id, NULL);
154 log_latency (gst_event_get_structure (ev), pad, ts);
155 gst_event_unref (ev);
161 do_push_buffer_post (GstTracer * self, guint64 ts, GstPad * pad)
163 GstPad *peer_pad = GST_PAD_PEER (pad);
164 GstElement *parent = get_real_pad_parent (peer_pad);
166 calculate_latency (parent, peer_pad, ts);
170 do_pull_range_post (GstTracer * self, guint64 ts, GstPad * pad)
172 GstElement *parent = get_real_pad_parent (pad);
174 calculate_latency (parent, pad, ts);
178 do_push_event_pre (GstTracer * self, guint64 ts, GstPad * pad, GstEvent * ev)
180 GstPad *peer_pad = GST_PAD_PEER (pad);
181 GstElement *parent = get_real_pad_parent (peer_pad);
183 if (parent && (!GST_IS_BIN (parent)) &&
184 GST_OBJECT_FLAG_IS_SET (parent, GST_ELEMENT_FLAG_SINK)) {
185 if (GST_EVENT_TYPE (ev) == GST_EVENT_CUSTOM_DOWNSTREAM) {
186 const GstStructure *data = gst_event_get_structure (ev);
188 if (gst_structure_get_name_id (data) == latency_probe_id) {
189 /* store event and calculate latency when the buffer that follows
190 * has been processed */
191 g_object_set_qdata ((GObject *) peer_pad, latency_probe_id,
201 gst_latency_tracer_class_init (GstLatencyTracerClass * klass)
203 latency_probe_id = g_quark_from_static_string ("latency_probe.id");
204 latency_probe_pad = g_quark_from_static_string ("latency_probe.pad");
205 latency_probe_ts = g_quark_from_static_string ("latency_probe.ts");
207 /* announce trace formats */
209 tr_latency = gst_tracer_record_new ("latency.class",
210 "src", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
211 "type", G_TYPE_GTYPE, G_TYPE_STRING,
212 "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
214 "sink", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
215 "type", G_TYPE_GTYPE, G_TYPE_STRING,
216 "related-to", GST_TYPE_TRACER_VALUE_SCOPE, GST_TRACER_VALUE_SCOPE_PAD,
218 "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
219 "type", G_TYPE_GTYPE, G_TYPE_UINT64,
220 "description", G_TYPE_STRING,
221 "time it took for the buffer to go from src to sink ns",
222 "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
223 "max", G_TYPE_UINT64, G_MAXUINT64,
230 gst_latency_tracer_init (GstLatencyTracer * self)
232 GstTracer *tracer = GST_TRACER (self);
233 gst_tracing_register_hook (tracer, "pad-push-pre",
234 G_CALLBACK (do_push_buffer_pre));
235 gst_tracing_register_hook (tracer, "pad-push-list-pre",
236 G_CALLBACK (do_push_buffer_pre));
237 gst_tracing_register_hook (tracer, "pad-push-post",
238 G_CALLBACK (do_push_buffer_post));
239 gst_tracing_register_hook (tracer, "pad-push-list-post",
240 G_CALLBACK (do_push_buffer_post));
241 gst_tracing_register_hook (tracer, "pad-pull-range-pre",
242 G_CALLBACK (do_pull_range_pre));
243 gst_tracing_register_hook (tracer, "pad-pull-range-post",
244 G_CALLBACK (do_pull_range_post));
245 gst_tracing_register_hook (tracer, "pad-push-event-pre",
246 G_CALLBACK (do_push_event_pre));