static GHashTable *threads = NULL;
static GPtrArray *elements = NULL;
static GPtrArray *pads = NULL;
+static GHashTable *latencies = NULL;
+static GHashTable *element_latencies = NULL;
+static GQueue *element_reported_latencies = NULL;
static guint64 num_buffers = 0, num_events = 0, num_messages = 0, num_queries =
0;
static guint num_elements = 0, num_bins = 0, num_pads = 0, num_ghostpads = 0;
static guint total_cpuload = 0;
static gboolean have_cpuload = FALSE;
+static gboolean have_latency = FALSE;
+static gboolean have_element_latency = FALSE;
+static gboolean have_element_reported_latency = FALSE;
+
+typedef struct
+{
+ /* the number of latencies counted */
+ guint64 count;
+ /* the total of all latencies */
+ guint64 total;
+ /* the min of all latencies */
+ guint64 min;
+ /* the max of all latencies */
+ guint64 max;
+} GstLatencyStats;
+
+typedef struct
+{
+ /* The element name */
+ gchar *element;
+ /* The timestamp of the reported latency */
+ guint64 ts;
+ /* the min reported latency */
+ guint64 min;
+ /* the max reported latency */
+ guint64 max;
+} GstReportedLatency;
+
typedef struct
{
/* human readable pad name and details */
/* stats helper */
static void
+latencies_foreach_print_stats (gchar * key, GstLatencyStats * ls, gpointer data)
+{
+ printf ("\t%s: mean=%" G_GUINT64_FORMAT " min=%" G_GUINT64_FORMAT " max=%"
+ G_GUINT64_FORMAT "\n", key, ls->total / ls->count, ls->min, ls->max);
+}
+
+static void
+reported_latencies_foreach_print_stats (GstReportedLatency * rl, gpointer data)
+{
+ printf ("\t%s: min=%" G_GUINT64_FORMAT " max=%" G_GUINT64_FORMAT " ts=%"
+ GST_TIME_FORMAT "\n", rl->element, rl->min,
+ rl->max, GST_TIME_ARGS (rl->ts));
+}
+
+static void
+free_latency_stats (gpointer data)
+{
+ g_slice_free (GstLatencyStats, data);
+}
+
+static void
+free_reported_latency (gpointer data)
+{
+ GstReportedLatency *rl = data;
+
+ if (rl->element)
+ g_free (rl->element);
+
+ g_free (data);
+}
+
+static void
free_element_stats (gpointer data)
{
g_slice_free (GstElementStats, data);
static void
do_buffer_stats (GstStructure * s)
{
- guint64 ts, buffer_pts, buffer_dur;
+ guint64 ts;
+ guint64 buffer_pts = GST_CLOCK_TIME_NONE, buffer_dur = GST_CLOCK_TIME_NONE;
guint pad_ix, elem_ix, peer_elem_ix;
guint size;
GstBufferFlags buffer_flags;
"element-ix", G_TYPE_UINT, &elem_ix,
"peer-element-ix", G_TYPE_UINT, &peer_elem_ix,
"buffer-size", G_TYPE_UINT, &size,
- "buffer-pts", G_TYPE_UINT64, &buffer_pts,
- "buffer-duration", G_TYPE_UINT64, &buffer_dur,
"buffer-flags", GST_TYPE_BUFFER_FLAGS, &buffer_flags, NULL);
+ gst_structure_get_uint64 (s, "buffer-pts", &buffer_pts);
+ gst_structure_get_uint64 (s, "buffer-duration", &buffer_dur);
last_ts = MAX (last_ts, ts);
if (!(pad_stats = get_pad_stats (pad_ix))) {
GST_WARNING ("no pad stats found for ix=%u", pad_ix);
have_cpuload = TRUE;
}
+static void
+update_latency_table (GHashTable * table, const gchar * key, guint64 time)
+{
+ /* Find the values in the hash table */
+ GstLatencyStats *ls = g_hash_table_lookup (table, key);
+ if (!ls) {
+ /* Insert the new key if the value does not exist */
+ ls = g_new0 (GstLatencyStats, 1);
+ ls->count = 1;
+ ls->total = time;
+ ls->min = time;
+ ls->max = time;
+ g_hash_table_insert (table, g_strdup (key), ls);
+ } else {
+ /* Otherwise update the existing value */
+ ls->count++;
+ ls->total += time;
+ if (ls->min > time)
+ ls->min = time;
+ if (ls->max < time)
+ ls->max = time;
+ }
+}
+
+static void
+do_latency_stats (GstStructure * s)
+{
+ gchar *key = NULL;
+ const gchar *src = NULL, *sink = NULL;
+ guint64 ts = 0, time = 0;
+
+ /* Get the values from the structure */
+ src = gst_structure_get_string (s, "src");
+ sink = gst_structure_get_string (s, "sink");
+ gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
+ gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
+
+ /* Update last_ts */
+ last_ts = MAX (last_ts, ts);
+
+ /* Get the key */
+ key = g_strjoin ("|", src, sink, NULL);
+
+ /* Update the latency in the table */
+ update_latency_table (latencies, key, time);
+
+ /* Clean up */
+ g_free (key);
+
+ have_latency = TRUE;
+}
+
+static void
+do_element_latency_stats (GstStructure * s)
+{
+ const gchar *src = NULL;
+ guint64 ts = 0, time = 0;
+
+ /* Get the values from the structure */
+ src = gst_structure_get_string (s, "src");
+ gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
+ gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
+
+ /* Update last_ts */
+ last_ts = MAX (last_ts, ts);
+
+ /* Update the latency in the table */
+ update_latency_table (element_latencies, src, time);
+
+ have_element_latency = TRUE;
+}
+
+static void
+do_element_reported_latency (GstStructure * s)
+{
+ const gchar *element = NULL;
+ guint64 ts = 0, min = 0, max = 0;
+ GstReportedLatency *rl = NULL;
+
+ /* Get the values from the structure */
+ element = gst_structure_get_string (s, "element");
+ gst_structure_get (s, "min", G_TYPE_UINT64, &min, NULL);
+ gst_structure_get (s, "max", G_TYPE_UINT64, &max, NULL);
+ gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
+
+ /* Update last_ts */
+ last_ts = MAX (last_ts, ts);
+
+ /* Insert/Update the key in the table */
+ rl = g_new0 (GstReportedLatency, 1);
+ rl->element = g_strdup (element);
+ rl->ts = ts;
+ rl->min = min;
+ rl->max = max;
+ g_queue_push_tail (element_reported_latencies, rl);
+
+ have_element_reported_latency = TRUE;
+}
+
/* reporting */
static gint
/* 1: ts */
"^([0-9:.]+) +"
/* 2: pid */
- "\\\e\\\[[0-9;]+m *([0-9]+)\\\e\\\[00m +"
+ "\\\x1b\\[[0-9;]+m *([0-9]+)\\\x1b\\[00m +"
/* 3: thread */
"(0x[0-9a-fA-F]+) +"
/* 4: level */
- "(?:\\\e\\\[[0-9;]+m)?([A-Z]+) +\\\e\\\[00m +"
+ "(?:\\\x1b\\[[0-9;]+m)?([A-Z]+) +\\\x1b\\[00m +"
/* 5: category */
- "\\\e\\\[[0-9;]+m +([a-zA-Z_-]+) +"
+ "\\\x1b\\[[0-9;]+m +([a-zA-Z_-]+) +"
/* 6: file:line:func: */
- "([^:]*:[0-9]+:[^:]*:)(?:\\\e\\\[00m)? +"
+ "([^:]*:[0-9]+:[^:]*:)(?:\\\x1b\\[00m)? +"
/* 7: (obj)? log-text */
"(.*)$", 0, 0, NULL);
if (!raw_log) {
elements = g_ptr_array_new_with_free_func (free_element_stats);
pads = g_ptr_array_new_with_free_func (free_pad_stats);
threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
+ latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
+ free_latency_stats);
+ element_latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
+ free_latency_stats);
+ element_reported_latencies = g_queue_new ();
return TRUE;
}
if (threads)
g_hash_table_destroy (threads);
+ if (latencies) {
+ g_hash_table_remove_all (latencies);
+ g_hash_table_destroy (latencies);
+ latencies = NULL;
+ }
+ if (element_latencies) {
+ g_hash_table_remove_all (element_latencies);
+ g_hash_table_destroy (element_latencies);
+ element_latencies = NULL;
+ }
+ if (element_reported_latencies) {
+ g_queue_free_full (element_reported_latencies, free_reported_latency);
+ element_reported_latencies = NULL;
+ }
+
if (raw_log)
g_regex_unref (raw_log);
if (ansi_log)
puts ("");
g_slist_free (list);
}
+
+ /* latency stats */
+ if (have_latency) {
+ puts ("Latency Statistics:");
+ g_hash_table_foreach (latencies, (GHFunc) latencies_foreach_print_stats,
+ NULL);
+ puts ("");
+ }
+
+ /* element latency stats */
+ if (have_element_latency) {
+ puts ("Element Latency Statistics:");
+ g_hash_table_foreach (element_latencies,
+ (GHFunc) latencies_foreach_print_stats, NULL);
+ puts ("");
+ }
+
+ /* element reported latency stats */
+ if (have_element_reported_latency) {
+ puts ("Element Reported Latency:");
+ g_queue_foreach (element_reported_latencies,
+ (GFunc) reported_latencies_foreach_print_stats, NULL);
+ puts ("");
+ }
}
static void
do_thread_rusage_stats (s);
} else if (!strcmp (name, "proc-rusage")) {
do_proc_rusage_stats (s);
+ } else if (!strcmp (name, "latency")) {
+ do_latency_stats (s);
+ } else if (!strcmp (name, "element-latency")) {
+ do_element_latency_stats (s);
+ } else if (!strcmp (name, "element-reported-latency")) {
+ do_element_reported_latency (s);
} else {
// TODO(ensonic): parse the xxx.class log lines
if (!g_str_has_suffix (data, ".class")) {