X-Git-Url: http://review.tizen.org/git/?a=blobdiff_plain;f=tools%2Fgst-stats.c;h=065f8ca89c5353f01e8b0bff9e239f510721c970;hb=5470f6df00595f4ab44871e0e633bf15006abc5c;hp=9ed50a043ff1b395078afacc507e8e887b4c6b7d;hpb=ff7ba1eb8dbc596a9f4988cb78cded527c7f97b3;p=platform%2Fupstream%2Fgstreamer.git diff --git a/tools/gst-stats.c b/tools/gst-stats.c index 9ed50a0..065f8ca 100644 --- a/tools/gst-stats.c +++ b/tools/gst-stats.c @@ -40,6 +40,9 @@ static GPtrArray *pads = 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 GstClockTime last_ts = G_GUINT64_CONSTANT (0); +static guint total_cpuload = 0; +static gboolean have_cpuload = FALSE; typedef struct { @@ -56,7 +59,7 @@ typedef struct /* first and last activity on the pad, expected next_ts */ GstClockTime first_ts, last_ts, next_ts; /* in which thread does it operate */ - guint thread_id; + gpointer thread_id; /* hierarchy */ guint parent_ix; } GstPadStats; @@ -74,8 +77,6 @@ typedef struct guint num_events, num_messages, num_queries; /* first activity on the element */ GstClockTime first_ts, last_ts; - /* time spend in this element */ - GstClockTime treal; /* hierarchy */ guint parent_ix; } GstElementStats; @@ -83,8 +84,8 @@ typedef struct typedef struct { /* time spend in this thread */ - GstClockTime treal; - guint max_cpuload; + GstClockTime tthread; + guint cpuload; } GstThreadStats; /* stats helper */ @@ -98,13 +99,15 @@ free_element_stats (gpointer data) static inline GstElementStats * get_element_stats (guint ix) { - return (ix != G_MAXUINT) ? g_ptr_array_index (elements, ix) : NULL; + return (ix != G_MAXUINT && ix < elements->len) ? + g_ptr_array_index (elements, ix) : NULL; } static inline GstPadStats * get_pad_stats (guint ix) { - return (ix != G_MAXUINT) ? g_ptr_array_index (pads, ix) : NULL; + return (ix != G_MAXUINT && ix < pads->len) ? + g_ptr_array_index (pads, ix) : NULL; } static void @@ -113,6 +116,19 @@ free_pad_stats (gpointer data) g_slice_free (GstPadStats, data); } +static inline GstThreadStats * +get_thread_stats (gpointer id) +{ + GstThreadStats *stats = g_hash_table_lookup (threads, id); + + if (G_UNLIKELY (!stats)) { + stats = g_slice_new0 (GstThreadStats); + stats->tthread = GST_CLOCK_TIME_NONE; + g_hash_table_insert (threads, id, stats); + } + return stats; +} + static void new_pad_stats (GstStructure * s) { @@ -121,7 +137,7 @@ new_pad_stats (GstStructure * s) gchar *type, *name; gboolean is_ghost_pad; GstPadDirection dir; - guint thread_id; + guint64 thread_id; gst_structure_get (s, "ix", G_TYPE_UINT, &ix, @@ -130,7 +146,7 @@ new_pad_stats (GstStructure * s) "type", G_TYPE_STRING, &type, "is-ghostpad", G_TYPE_BOOLEAN, &is_ghost_pad, "pad-direction", GST_TYPE_PAD_DIRECTION, &dir, - "thread-id", G_TYPE_UINT, &thread_id, NULL); + "thread-id", G_TYPE_UINT64, &thread_id, NULL); stats = g_slice_new0 (GstPadStats); if (is_ghost_pad) @@ -143,21 +159,12 @@ new_pad_stats (GstStructure * s) stats->dir = dir; stats->min_size = G_MAXUINT; stats->first_ts = stats->last_ts = stats->next_ts = GST_CLOCK_TIME_NONE; - stats->thread_id = thread_id; + stats->thread_id = (gpointer) (guintptr) thread_id; stats->parent_ix = parent_ix; if (pads->len <= ix) g_ptr_array_set_size (pads, ix + 1); g_ptr_array_index (pads, ix) = stats; - - if (thread_id) { - GstThreadStats *thread_stats; - if (!(thread_stats = g_hash_table_lookup (threads, - GUINT_TO_POINTER (thread_id)))) { - thread_stats = g_slice_new0 (GstThreadStats); - g_hash_table_insert (threads, GUINT_TO_POINTER (thread_id), thread_stats); - } - } } static void @@ -207,6 +214,10 @@ do_pad_stats (GstPadStats * stats, guint elem_ix, guint size, guint64 ts, stats->parent_ix = elem_ix; } + if (stats->thread_id) { + get_thread_stats (stats->thread_id); + } + /* size stats */ avg_size = (((gulong) stats->avg_size * (gulong) stats->num_buffers) + size); stats->num_buffers++; @@ -269,7 +280,8 @@ do_element_stats (GstElementStats * stats, GstElementStats * peer_stats, static void do_buffer_stats (GstStructure * s) { - guint64 ts, buffer_ts, 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; @@ -279,12 +291,13 @@ do_buffer_stats (GstStructure * s) num_buffers++; gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, "pad-ix", G_TYPE_UINT, &pad_ix, - "elem-ix", G_TYPE_UINT, &elem_ix, - "peer-elem-ix", G_TYPE_UINT, &peer_elem_ix, + "element-ix", G_TYPE_UINT, &elem_ix, + "peer-element-ix", G_TYPE_UINT, &peer_elem_ix, "buffer-size", G_TYPE_UINT, &size, - "buffer-ts", G_TYPE_UINT64, &buffer_ts, - "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); return; @@ -297,7 +310,7 @@ do_buffer_stats (GstStructure * s) GST_WARNING ("no element stats found for ix=%u", peer_elem_ix); return; } - do_pad_stats (pad_stats, elem_ix, size, ts, buffer_ts, buffer_dur, + do_pad_stats (pad_stats, elem_ix, size, ts, buffer_pts, buffer_dur, buffer_flags); if (pad_stats->dir == GST_PAD_SRC) { /* push */ @@ -318,7 +331,9 @@ do_event_stats (GstStructure * s) num_events++; gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, - "pad-ix", G_TYPE_UINT, &pad_ix, "elem-ix", G_TYPE_UINT, &elem_ix, NULL); + "pad-ix", G_TYPE_UINT, &pad_ix, "element-ix", G_TYPE_UINT, &elem_ix, + NULL); + 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); return; @@ -340,7 +355,8 @@ do_message_stats (GstStructure * s) num_messages++; gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, - "elem-ix", G_TYPE_UINT, &elem_ix, NULL); + "element-ix", G_TYPE_UINT, &elem_ix, NULL); + last_ts = MAX (last_ts, ts); if (!(elem_stats = get_element_stats (elem_ix))) { GST_WARNING ("no element stats found for ix=%u", elem_ix); return; @@ -357,7 +373,8 @@ do_query_stats (GstStructure * s) num_queries++; gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, - "elem-ix", G_TYPE_UINT, &elem_ix, NULL); + "element-ix", G_TYPE_UINT, &elem_ix, NULL); + last_ts = MAX (last_ts, ts); if (!(elem_stats = get_element_stats (elem_ix))) { GST_WARNING ("no element stats found for ix=%u", elem_ix); return; @@ -365,6 +382,34 @@ do_query_stats (GstStructure * s) elem_stats->num_queries++; } +static void +do_thread_rusage_stats (GstStructure * s) +{ + guint64 ts, tthread, thread_id; + guint cpuload; + GstThreadStats *thread_stats; + + gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, + "thread-id", G_TYPE_UINT64, &thread_id, + "average-cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread, + NULL); + thread_stats = get_thread_stats ((gpointer) (guintptr) thread_id); + thread_stats->cpuload = cpuload; + thread_stats->tthread = tthread; + last_ts = MAX (last_ts, ts); +} + +static void +do_proc_rusage_stats (GstStructure * s) +{ + guint64 ts; + + gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, + "average-cpuload", G_TYPE_UINT, &total_cpuload, NULL); + last_ts = MAX (last_ts, ts); + have_cpuload = TRUE; +} + /* reporting */ static gint @@ -372,8 +417,7 @@ find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data) { const GstPadStats *stats = (const GstPadStats *) value; - if ((stats->thread_id == GPOINTER_TO_UINT (user_data)) && - (stats->num_buffers)) { + if ((stats->thread_id == user_data) && (stats->num_buffers)) { return 0; } return 1; @@ -384,7 +428,7 @@ print_pad_stats (gpointer value, gpointer user_data) { GstPadStats *stats = (GstPadStats *) value; - if (stats->thread_id == GPOINTER_TO_UINT (user_data)) { + if (stats->thread_id == user_data) { /* there seem to be some temporary pads */ if (stats->num_buffers) { GstClockTimeDiff running = @@ -422,36 +466,17 @@ print_thread_stats (gpointer key, gpointer value, gpointer user_data) { GSList *list = user_data; GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread); + GstThreadStats *stats = (GstThreadStats *) value; /* skip stats if there are no pads for that thread (e.g. a pipeline) */ if (!node) return; -#if 0 - GstThreadStats *stats = (GstThreadStats *) value; - guint cpuload = 0; - guint time_percent; - - time_percent = - (guint) gst_util_uint64_scale (stats->treal, G_GINT64_CONSTANT (100), - last_ts); - - if (tusersys) { - guint64 total; - /* cpuload for the process, scaled by the timeslice of this thread */ - //cpuload = (guint) gst_util_uint64_scale (tusersys, G_GINT64_CONSTANT(100) * stats->treal, last_ts * last_ts); - - total = gst_util_uint64_scale (tusersys, G_GINT64_CONSTANT (100), last_ts); - cpuload = gst_util_uint64_scale (total, stats->treal, last_ts); - } -#endif - printf ("Thread %p Statistics:\n", key); -#if 0 - printf (" Time: %" GST_TIME_FORMAT ", %u %%\n", GST_TIME_ARGS (stats->treal), - (guint) time_percent); - printf (" Avg/Max CPU load: %u %%, %u %%\n", cpuload, stats->max_cpuload); -#endif + if (GST_CLOCK_TIME_IS_VALID (stats->tthread)) { + printf (" Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread)); + printf (" Avg CPU load: %4.1f %%\n", (gfloat) stats->cpuload / 10.0); + } puts (" Pad Statistics:"); g_slist_foreach (node, print_pad_stats, key); @@ -464,7 +489,6 @@ print_element_stats (gpointer value, gpointer user_data) /* skip temporary elements */ if (stats->first_ts != GST_CLOCK_TIME_NONE) { - //GstClockTimeDiff running = GST_CLOCK_DIFF (stats->first_ts, stats->last_ts); gchar fullname[45 + 1]; g_snprintf (fullname, 45, "%s:%s", stats->type_name, stats->name); @@ -486,10 +510,9 @@ print_element_stats (gpointer value, gpointer user_data) printf ("/%12" G_GUINT64_FORMAT, stats->sent_bytes); else printf ("/%12s", "-"); - printf (" first activity %" GST_TIME_FORMAT ", " " ev/msg/qry sent %5u/%5u/%5u" /*", " - " cpu usage %u %%" */ - "\n", GST_TIME_ARGS (stats->first_ts), stats->num_events, stats->num_messages, stats->num_queries /*, - (guint)(100*stats->treal/last_ts) */ ); + printf (" first activity %" GST_TIME_FORMAT ", " + " ev/msg/qry sent %5u/%5u/%5u\n", GST_TIME_ARGS (stats->first_ts), + stats->num_events, stats->num_messages, stats->num_queries); } } @@ -614,7 +637,7 @@ init (void) /* 5: category */ "([a-zA-Z_-]+) +" /* 6: file:line:func: */ - "([^:]+:[0-9]+:[^:]+:)" + "([^:]*:[0-9]+:[^:]*:) +" /* 7: (obj)? log-text */ "(.*)$", 0, 0, NULL); if (!raw_log) { @@ -626,15 +649,15 @@ init (void) /* 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) { @@ -681,6 +704,10 @@ print_stats (void) printf ("Number of Events sent: %" G_GUINT64_FORMAT "\n", num_events); printf ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages); printf ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries); + printf ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts)); + if (have_cpuload) { + printf ("Avg CPU load: %4.1f %%\n", (gfloat) total_cpuload / 10.0); + } puts (""); /* thread stats */ @@ -769,8 +796,6 @@ collect_stats (const gchar * filename) if ((s = gst_structure_from_string (data, NULL))) { const gchar *name = gst_structure_get_name (s); - // TODO(ensonic): add a function for each name-id quark - // these function will do the actual stats tracking if (!strcmp (name, "new-pad")) { new_pad_stats (s); } else if (!strcmp (name, "new-element")) { @@ -783,8 +808,15 @@ collect_stats (const gchar * filename) do_message_stats (s); } else if (!strcmp (name, "query")) { do_query_stats (s); + } else if (!strcmp (name, "thread-rusage")) { + do_thread_rusage_stats (s); + } else if (!strcmp (name, "proc-rusage")) { + do_proc_rusage_stats (s); } else { - GST_WARNING ("unknown log entry: '%s'", data); + // TODO(ensonic): parse the xxx.class log lines + if (!g_str_has_suffix (data, ".class")) { + GST_WARNING ("unknown log entry: '%s'", data); + } } gst_structure_free (s); } else { @@ -807,11 +839,10 @@ collect_stats (const gchar * filename) } } } - fclose (log); - // TODO(ensonic): print stats } else { GST_WARNING ("empty log"); } + fclose (log); } }