profile: Update to uprof-0.3 dep for --enable-profile
When building with --enable-profile we now depend on the uprof-0.3 developer release which brings a few improvements: » It lets us "fix" how we initialize uprof so that instead of using a shared object constructor/destructor (which was a hack used when first adding uprof support to Clutter) we can now initialize as part of clutter's normal initialization code. As a side note though, I found that the way Clutter initializes has some quite serious problems whenever it involves GOptionGroups. It is not able to guarantee the initialization of dependencies like uprof and Cogl. For this reason we still use the contructor/destructor approach to initialize uprof in Cogl. » uprof-0.3 provides a better API for adding custom columns when reporting timer and counter statistics which lets us remove quite a lot of manual report generation code in clutter-profile.c. » uprof-0.3 provides a shared context for tracking mainloop timer statistics. This means any mainloop based library following the same "Mainloop" timer naming convention can use the shared context and no matter who ends up owning the final mainloop the statistics will always be in the same place. This allows profiling of Clutter with an external mainloop such as with the Mutter compositor. » uprof-0.3 can export statistics over dbus and comes with an ncurses based ui to vizualize timer and counter stats live. The latest version of uprof can be cloned from: git://github.com/rib/UProf.git
This commit is contained in:
Robert Bragg
@ -6,7 +6,8 @@
|
||||
#include <stdlib.h>
|
||||
|
||||
UProfContext *_clutter_uprof_context;
|
||||
#define REPORT_COLUMN0_WIDTH 40
|
||||
|
||||
static UProfReport *clutter_uprof_report;
|
||||
|
||||
static gboolean searched_for_gl_uprof_context = FALSE;
|
||||
static UProfContext *gl_uprof_context = NULL;
|
||||
@ -14,164 +15,245 @@ static UProfContext *gl_uprof_context = NULL;
|
||||
typedef struct _ClutterUProfReportState
|
||||
{
|
||||
gulong n_frames;
|
||||
float fps;
|
||||
gulong n_picks;
|
||||
float msecs_picking;
|
||||
} ClutterUProfReportState;
|
||||
|
||||
static void
|
||||
print_counter (UProfCounterResult *counter,
|
||||
gpointer data)
|
||||
{
|
||||
ClutterUProfReportState *state = data;
|
||||
gulong count = uprof_counter_result_get_count (counter);
|
||||
if (count == 0)
|
||||
return;
|
||||
|
||||
g_print (" %-*s %-5ld %-5ld\n", REPORT_COLUMN0_WIDTH - 2,
|
||||
uprof_counter_result_get_name (counter),
|
||||
uprof_counter_result_get_count (counter),
|
||||
uprof_counter_result_get_count (counter) / state->n_frames);
|
||||
}
|
||||
|
||||
static char *
|
||||
print_timer_fields (UProfTimerResult *timer,
|
||||
guint *fields_width,
|
||||
gpointer data)
|
||||
timer_per_frame_cb (UProfReport *report,
|
||||
UProfTimerResult *timer,
|
||||
void *user_data)
|
||||
{
|
||||
ClutterUProfReportState *state = data;
|
||||
/* Print the field titles when timer == NULL */
|
||||
if (!timer)
|
||||
return g_strdup_printf ("Per Frame");
|
||||
ClutterUProfReportState *state = user_data;
|
||||
int n_frames = state->n_frames ? state->n_frames : 1;
|
||||
|
||||
return g_strdup_printf ("%-10.2f",
|
||||
uprof_timer_result_get_total_msecs (timer) /
|
||||
(float)state->n_frames);
|
||||
(float)n_frames);
|
||||
}
|
||||
|
||||
static void
|
||||
print_report (UProfReport *report, UProfContext *context)
|
||||
static char *
|
||||
counter_per_frame_cb (UProfReport *report,
|
||||
UProfCounterResult *counter,
|
||||
void *user_data)
|
||||
{
|
||||
GList *root_timers;
|
||||
GList *l;
|
||||
UProfTimerResult *stage_paint_timer;
|
||||
UProfTimerResult *mainloop_timer;
|
||||
UProfTimerResult *do_pick_timer;
|
||||
float fps;
|
||||
ClutterUProfReportState state;
|
||||
ClutterUProfReportState *state = user_data;
|
||||
int n_frames = state->n_frames ? state->n_frames : 1;
|
||||
|
||||
/* FIXME: We need to fix the way Clutter initializes the uprof library
|
||||
* (we don't currently call uprof_init()) and add a mechanism to know
|
||||
* if uprof_init hasn't been called so we can simply bail out of report
|
||||
* generation and not print spurious warning about missing timers.
|
||||
* Probably we can just have uprof_report_print bail out if uprof wasn't
|
||||
* initialized, so we don't have to care here.
|
||||
*/
|
||||
mainloop_timer = uprof_context_get_timer_result (context, "Mainloop");
|
||||
stage_paint_timer = uprof_context_get_timer_result (context, "Redrawing");
|
||||
do_pick_timer = uprof_context_get_timer_result (context, "Do pick");
|
||||
return g_strdup_printf ("%-5ld",
|
||||
uprof_counter_result_get_count (counter) /
|
||||
n_frames);
|
||||
}
|
||||
|
||||
static char *
|
||||
get_n_frames_cb (UProfReport *report,
|
||||
const char *statistic,
|
||||
const char *attribute,
|
||||
void *user_data)
|
||||
{
|
||||
ClutterUProfReportState *state = user_data;
|
||||
|
||||
return g_strdup_printf ("%lu", state->n_frames);
|
||||
}
|
||||
|
||||
static char *
|
||||
get_fps_cb (UProfReport *report,
|
||||
const char *statistic,
|
||||
const char *attribute,
|
||||
void *user_data)
|
||||
{
|
||||
ClutterUProfReportState *state = user_data;
|
||||
|
||||
return g_strdup_printf ("%5.2f\n", state->fps);
|
||||
}
|
||||
|
||||
static char *
|
||||
get_n_picks_cb (UProfReport *report,
|
||||
const char *statistic,
|
||||
const char *attribute,
|
||||
void *user_data)
|
||||
{
|
||||
ClutterUProfReportState *state = user_data;
|
||||
|
||||
return g_strdup_printf ("%lu", state->n_picks);
|
||||
}
|
||||
|
||||
static char *
|
||||
get_picks_per_frame_cb (UProfReport *report,
|
||||
const char *statistic,
|
||||
const char *attribute,
|
||||
void *user_data)
|
||||
{
|
||||
ClutterUProfReportState *state = user_data;
|
||||
int n_frames = state->n_frames ? state->n_frames : 1;
|
||||
|
||||
return g_strdup_printf ("%3.2f",
|
||||
(float)state->n_picks / (float)n_frames);
|
||||
}
|
||||
|
||||
static char *
|
||||
get_msecs_per_pick_cb (UProfReport *report,
|
||||
const char *statistic,
|
||||
const char *attribute,
|
||||
void *user_data)
|
||||
{
|
||||
ClutterUProfReportState *state = user_data;
|
||||
int n_picks = state->n_picks ? state->n_picks : 1;
|
||||
|
||||
return g_strdup_printf ("%3.2f", state->msecs_picking / (float)n_picks);
|
||||
}
|
||||
|
||||
static gboolean
|
||||
_clutter_uprof_report_prepare (UProfReport *report,
|
||||
void **closure_ret,
|
||||
void *user_data)
|
||||
{
|
||||
UProfContext *mainloop_context;
|
||||
UProfTimerResult *mainloop_timer;
|
||||
UProfTimerResult *stage_paint_timer;
|
||||
UProfTimerResult *do_pick_timer;
|
||||
ClutterUProfReportState *state;
|
||||
|
||||
/* NB: uprof provides a shared context for mainloop statistics which allows
|
||||
* this to work even if the application and not Clutter owns the mainloop.
|
||||
*
|
||||
* This is the case when running Mutter for example but because Mutter will
|
||||
* follow the same convention of using the shared context then we can always
|
||||
* be sure of where to look for the mainloop results. */
|
||||
mainloop_context = uprof_get_mainloop_context ();
|
||||
mainloop_timer = uprof_context_get_timer_result (mainloop_context,
|
||||
"Mainloop");
|
||||
/* just bail out if the mainloop timer wasn't hit */
|
||||
if (!mainloop_timer)
|
||||
return FALSE;
|
||||
|
||||
state = g_new0 (ClutterUProfReportState, 1);
|
||||
*closure_ret = state;
|
||||
|
||||
stage_paint_timer = uprof_context_get_timer_result (_clutter_uprof_context,
|
||||
"Redrawing");
|
||||
if (stage_paint_timer)
|
||||
{
|
||||
g_print ("\n");
|
||||
state->n_frames = uprof_timer_result_get_start_count (stage_paint_timer);
|
||||
|
||||
state.n_frames = uprof_timer_result_get_start_count (stage_paint_timer);
|
||||
g_print ("Frame count = %lu\n", state.n_frames);
|
||||
uprof_report_add_statistic (report,
|
||||
"Frames",
|
||||
"Frame count information");
|
||||
uprof_report_add_statistic_attribute (report, "Frames",
|
||||
"Count", "Count",
|
||||
"The total number of frames",
|
||||
UPROF_ATTRIBUTE_TYPE_INT,
|
||||
get_n_frames_cb,
|
||||
state);
|
||||
|
||||
fps = (float) state.n_frames
|
||||
/ (uprof_timer_result_get_total_msecs (mainloop_timer)
|
||||
/ 1000.0);
|
||||
g_print ("Average fps = %5.2f\n", fps);
|
||||
|
||||
state->fps = (float) state->n_frames
|
||||
/ (uprof_timer_result_get_total_msecs (mainloop_timer)
|
||||
/ 1000.0);
|
||||
uprof_report_add_statistic_attribute (report, "Frames",
|
||||
"Average FPS", "Average\nFPS",
|
||||
"The average frames per second",
|
||||
UPROF_ATTRIBUTE_TYPE_FLOAT,
|
||||
get_fps_cb,
|
||||
state);
|
||||
}
|
||||
|
||||
do_pick_timer = uprof_context_get_timer_result (_clutter_uprof_context,
|
||||
"Picking");
|
||||
if (do_pick_timer)
|
||||
{
|
||||
int n_picks = uprof_timer_result_get_start_count (do_pick_timer);
|
||||
state->n_picks = uprof_timer_result_get_start_count (do_pick_timer);
|
||||
state->msecs_picking =
|
||||
uprof_timer_result_get_total_msecs (do_pick_timer);
|
||||
|
||||
g_print ("\n");
|
||||
uprof_report_add_statistic (report,
|
||||
"Picks",
|
||||
"Picking information");
|
||||
uprof_report_add_statistic_attribute (report, "Picks",
|
||||
"Count", "Count",
|
||||
"The total number of picks",
|
||||
UPROF_ATTRIBUTE_TYPE_INT,
|
||||
get_n_picks_cb,
|
||||
state);
|
||||
|
||||
g_print ("Pick Stats:\n");
|
||||
g_print ("Pick count = %d\n", n_picks);
|
||||
g_print ("Average picks per frame = %3.2f\n",
|
||||
(float)n_picks / (float)state.n_frames);
|
||||
g_print ("Average Msecs per pick = %3.2f\n",
|
||||
(float)uprof_timer_result_get_total_msecs (do_pick_timer)
|
||||
/ (float)n_picks);
|
||||
uprof_report_add_statistic_attribute (report, "Picks",
|
||||
"Picks Per Frame",
|
||||
"Picks\nPer Frame",
|
||||
"The average number of picks "
|
||||
"per frame",
|
||||
UPROF_ATTRIBUTE_TYPE_FLOAT,
|
||||
get_picks_per_frame_cb,
|
||||
state);
|
||||
|
||||
uprof_report_add_statistic_attribute (report, "Picks",
|
||||
"Msecs Per Pick",
|
||||
"Msecs\nPer Pick",
|
||||
"The average number of "
|
||||
"milliseconds per pick",
|
||||
UPROF_ATTRIBUTE_TYPE_FLOAT,
|
||||
get_msecs_per_pick_cb,
|
||||
state);
|
||||
}
|
||||
|
||||
root_timers = uprof_context_get_root_timer_results (context);
|
||||
if (!root_timers)
|
||||
return;
|
||||
uprof_report_add_counters_attribute (clutter_uprof_report,
|
||||
"Per Frame",
|
||||
"Per Frame",
|
||||
"The number of counts per frame",
|
||||
UPROF_ATTRIBUTE_TYPE_INT,
|
||||
counter_per_frame_cb,
|
||||
state);
|
||||
uprof_report_add_timers_attribute (clutter_uprof_report,
|
||||
"Per Frame",
|
||||
"Per Frame",
|
||||
"The amount of timer per frame",
|
||||
UPROF_ATTRIBUTE_TYPE_FLOAT,
|
||||
timer_per_frame_cb,
|
||||
state);
|
||||
|
||||
g_print ("\n");
|
||||
|
||||
/* XXX: UProfs default reporting code now supports dynamic sizing for the Name
|
||||
* column, the only thing it's missing is support for adding custom columns but
|
||||
* when that's added we should switch away from manual report generation. */
|
||||
g_print ("Counters:\n");
|
||||
g_print (" %-*s %5s %s\n", REPORT_COLUMN0_WIDTH - 2, "Name", "Total", "Per Frame");
|
||||
g_print (" %-*s %5s %s\n", REPORT_COLUMN0_WIDTH - 2, "----", "-----", "---------");
|
||||
uprof_context_foreach_counter (context,
|
||||
UPROF_COUNTER_SORT_COUNT_INC,
|
||||
print_counter,
|
||||
&state);
|
||||
|
||||
g_print ("\n");
|
||||
g_print ("Timers:\n");
|
||||
for (l = root_timers; l != NULL; l = l->next)
|
||||
uprof_timer_result_print_and_children ((UProfTimerResult *)l->data,
|
||||
print_timer_fields,
|
||||
&state);
|
||||
|
||||
g_print ("\n");
|
||||
return TRUE;
|
||||
}
|
||||
|
||||
/* FIXME: we should be able to deal with creating the uprof context in
|
||||
* clutter_init instead. I think the only reason I did it this way originally
|
||||
* was as a quick hack.
|
||||
*/
|
||||
static void __attribute__ ((constructor))
|
||||
clutter_uprof_constructor (void)
|
||||
{
|
||||
_clutter_uprof_context = uprof_context_new ("Clutter");
|
||||
}
|
||||
|
||||
#if 0
|
||||
static void
|
||||
print_timers (UProfContext *context)
|
||||
_clutter_uprof_report_done (UProfReport *report, void *closure, void *user_data)
|
||||
{
|
||||
GList *root_timers;
|
||||
GList *l;
|
||||
|
||||
root_timers = uprof_context_get_root_timer_results ();
|
||||
|
||||
root_timers =
|
||||
g_list_sort_with_data (context->root_timers,
|
||||
(GCompareDataFunc)_uprof_timer_compare_total_times,
|
||||
NULL);
|
||||
for (l = context->timers; l != NULL; l = l->next)
|
||||
{
|
||||
UProfTimerState *timer = l->data;
|
||||
timer->children =
|
||||
g_list_sort_with_data (timer->children,
|
||||
(GCompareDataFunc)
|
||||
_uprof_timer_compare_total_times,
|
||||
NULL);
|
||||
}
|
||||
g_free (closure);
|
||||
}
|
||||
#endif
|
||||
|
||||
static void __attribute__ ((destructor))
|
||||
clutter_uprof_destructor (void)
|
||||
static void
|
||||
print_exit_report (void)
|
||||
{
|
||||
if (!(clutter_profile_flags & CLUTTER_PROFILE_DISABLE_REPORT))
|
||||
{
|
||||
UProfReport *report = uprof_report_new ("Clutter report");
|
||||
uprof_report_add_context (report, _clutter_uprof_context);
|
||||
uprof_report_add_context_callback (report, print_report);
|
||||
uprof_report_print (report);
|
||||
uprof_report_unref (report);
|
||||
}
|
||||
uprof_report_print (clutter_uprof_report);
|
||||
|
||||
uprof_report_unref (clutter_uprof_report);
|
||||
|
||||
uprof_context_unref (_clutter_uprof_context);
|
||||
}
|
||||
|
||||
void
|
||||
_clutter_uprof_init (void)
|
||||
{
|
||||
UProfContext *cogl_context;
|
||||
|
||||
_clutter_uprof_context = uprof_context_new ("Clutter");
|
||||
uprof_context_link (_clutter_uprof_context, uprof_get_mainloop_context ());
|
||||
g_atexit (print_exit_report);
|
||||
|
||||
cogl_context = uprof_find_context ("Cogl");
|
||||
if (cogl_context)
|
||||
uprof_context_link (_clutter_uprof_context, cogl_context);
|
||||
|
||||
/* We make the report object up-front so we can use uprof-tool
|
||||
* to fetch reports at runtime via dbus... */
|
||||
clutter_uprof_report = uprof_report_new ("Clutter report");
|
||||
uprof_report_add_context (clutter_uprof_report, _clutter_uprof_context);
|
||||
uprof_report_set_init_fini_callbacks (clutter_uprof_report,
|
||||
_clutter_uprof_report_prepare,
|
||||
_clutter_uprof_report_done,
|
||||
NULL);
|
||||
}
|
||||
|
||||
void
|
||||
_clutter_profile_suspend (void)
|
||||
{
|
||||
@ -198,5 +280,18 @@ _clutter_profile_resume (void)
|
||||
uprof_context_resume (_clutter_uprof_context);
|
||||
}
|
||||
|
||||
void
|
||||
_clutter_profile_trace_message (const char *format, ...)
|
||||
{
|
||||
va_list ap;
|
||||
|
||||
va_start (ap, format);
|
||||
g_logv (G_LOG_DOMAIN, G_LOG_LEVEL_MESSAGE, format, ap);
|
||||
va_end (ap);
|
||||
|
||||
if (_clutter_uprof_context)
|
||||
uprof_context_vtrace_message (_clutter_uprof_context, format, ap);
|
||||
}
|
||||
|
||||
#endif
|
||||
|
||||
|
||||
Reference in New Issue
Block a user