diff --git a/clutter/Makefile.am b/clutter/Makefile.am index 315144185..196d6ce43 100644 --- a/clutter/Makefile.am +++ b/clutter/Makefile.am @@ -106,6 +106,7 @@ source_h = \ $(srcdir)/clutter-types.h \ $(srcdir)/clutter-units.h \ $(srcdir)/clutter-util.h \ + $(srcdir)/clutter-profile.h \ $(top_builddir)/clutter/clutter-version.h \ $(NULL) @@ -180,6 +181,7 @@ source_c = \ $(srcdir)/clutter-timeout-pool.c \ $(srcdir)/clutter-units.c \ $(srcdir)/clutter-util.c \ + $(srcdir)/clutter-profile.c \ $(NULL) source_h_priv = \ diff --git a/clutter/clutter-actor.c b/clutter/clutter-actor.c index 724a2ac49..c873236b4 100644 --- a/clutter/clutter-actor.c +++ b/clutter/clutter-actor.c @@ -204,6 +204,7 @@ #include "clutter-private.h" #include "clutter-debug.h" #include "clutter-units.h" +#include "clutter-profile.h" #include "cogl/cogl.h" typedef struct _ShaderData ShaderData; @@ -2367,6 +2368,15 @@ clutter_actor_paint (ClutterActor *self) ClutterActorPrivate *priv; ClutterMainContext *context; gboolean clip_set = FALSE; + CLUTTER_STATIC_COUNTER (actor_paint_counter, + "Actor real-paint counter", + "Increments each time any actor is painted", + 0 /* no application private data */); + CLUTTER_STATIC_COUNTER (actor_pick_counter, + "Actor pick-paint counter", + "Increments each time any actor is painted " + "for picking", + 0 /* no application private data */); g_return_if_fail (CLUTTER_IS_ACTOR (self)); @@ -2422,6 +2432,8 @@ clutter_actor_paint (ClutterActor *self) { ClutterColor col = { 0, }; + CLUTTER_COUNTER_INC (_clutter_uprof_context, actor_pick_counter); + _clutter_id_to_color (clutter_actor_get_gid (self), &col); /* Actor will then paint silhouette of itself in supplied @@ -2432,6 +2444,8 @@ clutter_actor_paint (ClutterActor *self) } else { + CLUTTER_COUNTER_INC (_clutter_uprof_context, actor_paint_counter); + clutter_actor_shader_pre_paint (self, FALSE); self->priv->queued_redraw = FALSE; diff --git a/clutter/clutter-backend.c b/clutter/clutter-backend.c index 3e70e255c..54c7fa963 100644 --- a/clutter/clutter-backend.c +++ b/clutter/clutter-backend.c @@ -46,6 +46,7 @@ #include "clutter-fixed.h" #include "clutter-marshal.h" #include "clutter-private.h" +#include "clutter-profile.h" #include @@ -302,10 +303,24 @@ _clutter_backend_redraw (ClutterBackend *backend, ClutterStage *stage) { ClutterBackendClass *klass; + CLUTTER_STATIC_COUNTER (redraw_counter, + "_clutter_backend_redraw counter", + "Increments for each _clutter_backend_redraw call", + 0 /* no application private data */); + CLUTTER_STATIC_TIMER (redraw_timer, + "Mainloop", /* parent */ + "Redrawing", + "The time spent redrawing everything", + 0 /* no application private data */); + + CLUTTER_COUNTER_INC (_clutter_uprof_context, redraw_counter); + CLUTTER_TIMER_START (_clutter_uprof_context, redraw_timer); klass = CLUTTER_BACKEND_GET_CLASS (backend); if (G_LIKELY (klass->redraw)) klass->redraw (backend, stage); + + CLUTTER_TIMER_STOP (_clutter_uprof_context, redraw_timer); } gboolean diff --git a/clutter/clutter-main.c b/clutter/clutter-main.c index 84f5ed696..f5f0afa21 100644 --- a/clutter/clutter-main.c +++ b/clutter/clutter-main.c @@ -109,6 +109,7 @@ #include "clutter-debug.h" #include "clutter-version.h" /* For flavour define */ #include "clutter-frame-source.h" +#include "clutter-profile.h" #include "cogl/cogl.h" #include "pango/cogl-pango.h" @@ -187,10 +188,16 @@ _clutter_stage_maybe_relayout (ClutterActor *stage) { gfloat natural_width, natural_height; ClutterActorBox box = { 0, }; + CLUTTER_STATIC_TIMER (relayout_timer, + "Mainloop", /* no parent */ + "Layouting", + "The time spent reallocating the stage", + 0 /* no application private data */); /* avoid reentrancy */ if (!(CLUTTER_PRIVATE_FLAGS (stage) & CLUTTER_ACTOR_IN_RELAYOUT)) { + CLUTTER_TIMER_START (_clutter_uprof_context, relayout_timer); CLUTTER_NOTE (ACTOR, "Recomputing layout"); CLUTTER_SET_PRIVATE_FLAGS (stage, CLUTTER_ACTOR_IN_RELAYOUT); @@ -212,6 +219,7 @@ _clutter_stage_maybe_relayout (ClutterActor *stage) clutter_actor_allocate (stage, &box, CLUTTER_ALLOCATION_NONE); CLUTTER_UNSET_PRIVATE_FLAGS (stage, CLUTTER_ACTOR_IN_RELAYOUT); + CLUTTER_TIMER_STOP (_clutter_uprof_context, relayout_timer); } } @@ -529,10 +537,39 @@ _clutter_do_pick (ClutterStage *stage, CoglColor stage_pick_id; guint32 id; GLboolean dither_was_on; + ClutterActor *actor; + CLUTTER_STATIC_COUNTER (do_pick_counter, + "_clutter_do_pick counter", + "Increments for each full pick run", + 0 /* no application private data */); + CLUTTER_STATIC_TIMER (pick_timer, + "Mainloop", /* parent */ + "Picking", + "The time spent picking", + 0 /* no application private data */); + CLUTTER_STATIC_TIMER (pick_clear, + "Picking", /* parent */ + "Stage clear (pick)", + "The time spent clearing stage for picking", + 0 /* no application private data */); + CLUTTER_STATIC_TIMER (pick_paint, + "Picking", /* parent */ + "Painting actors (pick mode)", + "The time spent painting actors in pick mode", + 0 /* no application private data */); + CLUTTER_STATIC_TIMER (pick_read, + "Picking", /* parent */ + "Read Pixels", + "The time spent issuing a read pixels", + 0 /* no application private data */); + if (clutter_debug_flags & CLUTTER_DEBUG_NOP_PICKING) return CLUTTER_ACTOR (stage); + CLUTTER_COUNTER_INC (_clutter_uprof_context, do_pick_counter); + CLUTTER_TIMER_START (_clutter_uprof_context, pick_timer); + context = _clutter_context_get_default (); _clutter_backend_ensure_context (context->backend, stage); @@ -545,9 +582,11 @@ _clutter_do_pick (ClutterStage *stage, cogl_disable_fog (); cogl_color_set_from_4ub (&stage_pick_id, 255, 255, 255, 255); + CLUTTER_TIMER_START (_clutter_uprof_context, pick_clear); cogl_clear (&stage_pick_id, COGL_BUFFER_BIT_COLOR | COGL_BUFFER_BIT_DEPTH); + CLUTTER_TIMER_STOP (_clutter_uprof_context, pick_clear); /* Disable dithering (if any) when doing the painting in pick mode */ dither_was_on = glIsEnabled (GL_DITHER); @@ -557,9 +596,11 @@ _clutter_do_pick (ClutterStage *stage, /* Render the entire scence in pick mode - just single colored silhouette's * are drawn offscreen (as we never swap buffers) */ + CLUTTER_TIMER_START (_clutter_uprof_context, pick_paint); context->pick_mode = mode; clutter_actor_paint (CLUTTER_ACTOR (stage)); context->pick_mode = CLUTTER_PICK_NONE; + CLUTTER_TIMER_STOP (_clutter_uprof_context, pick_paint); if (G_LIKELY (!(clutter_debug_flags & CLUTTER_DEBUG_DUMP_PICK_BUFFERS))) cogl_clip_pop (); @@ -568,10 +609,12 @@ _clutter_do_pick (ClutterStage *stage, cogl_flush (); /* Read the color of the screen co-ords pixel */ + CLUTTER_TIMER_START (_clutter_uprof_context, pick_read); cogl_read_pixels (x, y, 1, 1, COGL_READ_PIXELS_COLOR_BUFFER, COGL_PIXEL_FORMAT_RGBA_8888, pixel); + CLUTTER_TIMER_STOP (_clutter_uprof_context, pick_read); if (G_UNLIKELY (clutter_debug_flags & CLUTTER_DEBUG_DUMP_PICK_BUFFERS)) { @@ -585,11 +628,17 @@ _clutter_do_pick (ClutterStage *stage, glEnable (GL_DITHER); if (pixel[0] == 0xff && pixel[1] == 0xff && pixel[2] == 0xff) - return CLUTTER_ACTOR (stage); + { + CLUTTER_TIMER_STOP (_clutter_uprof_context, pick_timer); + return CLUTTER_ACTOR (stage); + } id = _clutter_pixel_to_id (pixel); + actor = clutter_get_actor_by_gid (id); - return clutter_get_actor_by_gid (id); + CLUTTER_TIMER_STOP (_clutter_uprof_context, pick_timer); + + return actor; } static ClutterTextDirection @@ -723,6 +772,28 @@ clutter_main_level (void) return clutter_main_loop_level; } +#ifdef CLUTTER_ENABLE_PROFILE +static gint (*prev_poll) (GPollFD *ufds, guint nfsd, gint timeout_) = NULL; + +static gint +timed_poll (GPollFD *ufds, + guint nfsd, + gint timeout_) +{ + gint ret; + CLUTTER_STATIC_TIMER (poll_timer, + "Mainloop", /* parent */ + "poll (idle)", + "The time spent idle in poll()", + 0 /* no application private data */); + + CLUTTER_TIMER_START (_clutter_uprof_context, poll_timer); + ret = prev_poll (ufds, nfsd, timeout_); + CLUTTER_TIMER_STOP (_clutter_uprof_context, poll_timer); + return ret; +} +#endif + /** * clutter_main: * @@ -732,6 +803,14 @@ void clutter_main (void) { GMainLoop *loop; + CLUTTER_STATIC_TIMER (mainloop_timer, + NULL, /* no parent */ + "Mainloop", + "The time spent in the clutter mainloop", + 0 /* no application private data */); + + if (clutter_main_loop_level == 0) + CLUTTER_TIMER_START (_clutter_uprof_context, mainloop_timer); /* Make sure there is a context */ CLUTTER_CONTEXT (); @@ -747,6 +826,14 @@ clutter_main (void) clutter_main_loop_level++; +#ifdef CLUTTER_ENABLE_PROFILE + if (!prev_poll) + { + prev_poll = g_main_context_get_poll_func (NULL); + g_main_context_set_poll_func (NULL, timed_poll); + } +#endif + loop = g_main_loop_new (NULL, TRUE); main_loops = g_slist_prepend (main_loops, loop); @@ -771,6 +858,9 @@ clutter_main (void) clutter_main_loop_level--; CLUTTER_MARK (); + + if (clutter_main_loop_level == 0) + CLUTTER_TIMER_STOP (_clutter_uprof_context, mainloop_timer); } static void diff --git a/clutter/clutter-profile.c b/clutter/clutter-profile.c new file mode 100644 index 000000000..f08d37306 --- /dev/null +++ b/clutter/clutter-profile.c @@ -0,0 +1,170 @@ + +#ifdef CLUTTER_ENABLE_PROFILE + +#include "clutter-profile.h" + +#include + +UProfContext *_clutter_uprof_context; +#define REPORT_COLUMN0_WIDTH 40 + +typedef struct _ClutterUProfReportState +{ + gulong n_frames; +} 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) +{ + ClutterUProfReportState *state = data; + /* Print the field titles when timer == NULL */ + if (!timer) + return g_strdup_printf ("Per Frame"); + + return g_strdup_printf ("%-10.2f", + uprof_timer_result_get_total_msecs (timer) / + (float)state->n_frames); +} + +static void +print_report (UProfReport *report, UProfContext *context) +{ + GList *root_timers; + GList *l; + UProfTimerResult *stage_paint_timer; + UProfTimerResult *mainloop_timer; + UProfTimerResult *do_pick_timer; + float fps; + ClutterUProfReportState state; + + g_print ("\n"); + + /* 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. + */ + + stage_paint_timer = uprof_context_get_timer_result (context, "Redrawing"); +#if 0 + if (!stage_paint_timer) + g_critical ("Failed to find \"Redrawing\" timer " + "(you need to update print_report code if you rename it)\n"); +#endif + + state.n_frames = uprof_timer_result_get_start_count (stage_paint_timer); + g_print ("Frame count = %lu\n", state.n_frames); + + mainloop_timer = uprof_context_get_timer_result (context, "Mainloop"); + fps = (float)state.n_frames / (uprof_timer_result_get_total_msecs (mainloop_timer) + / 1000.0); + g_print ("Average fps = %5.2f\n", fps); + + do_pick_timer = uprof_context_get_timer_result (context, "Do pick"); + if (do_pick_timer) + { + int n_picks = uprof_timer_result_get_start_count (do_pick_timer); + + 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); + + 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"); + root_timers = uprof_context_get_root_timer_results (context); + 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"); +} + +/* 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) +{ + 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); + } +} +#endif + +static void __attribute__ ((destructor)) +clutter_uprof_destructor (void) +{ + if (getenv ("CLUTTER_PROFILE_OUTPUT_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_context_unref (_clutter_uprof_context); +} + +#endif + diff --git a/clutter/clutter-profile.h b/clutter/clutter-profile.h new file mode 100644 index 000000000..a8c57c6ec --- /dev/null +++ b/clutter/clutter-profile.h @@ -0,0 +1,57 @@ +/* + * Clutter. + * + * An OpenGL based 'interactive canvas' library. + * + * Copyright (C) 2009 Intel Corporation. + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library. If not, see . + */ + +#if !defined(__CLUTTER_H_INSIDE__) && !defined(CLUTTER_COMPILATION) +#error "Only can be included directly." +#endif + +#ifndef _CLUTTER_PROFILE_H_ +#define _CLUTTER_PROFILE_H_ + +G_BEGIN_DECLS + +#ifdef CLUTTER_ENABLE_PROFILE + +#include + +extern UProfContext *_clutter_uprof_context; + +#define CLUTTER_STATIC_TIMER UPROF_STATIC_TIMER +#define CLUTTER_STATIC_COUNTER UPROF_STATIC_COUNTER +#define CLUTTER_COUNTER_INC UPROF_COUNTER_INC +#define CLUTTER_COUNTER_DEC UPROF_COUNTER_DEC +#define CLUTTER_TIMER_START UPROF_TIMER_START +#define CLUTTER_TIMER_STOP UPROF_TIMER_STOP + +#else /* CLUTTER_ENABLE_PROFILE */ + +#define CLUTTER_STATIC_TIMER(A,B,C,D,E) extern void _clutter_dummy_decl (void) +#define CLUTTER_STATIC_COUNTER(A,B,C,D) extern void _clutter_dummy_decl (void) +#define CLUTTER_COUNTER_INC(A,B) G_STMT_START{ (void)0; }G_STMT_END +#define CLUTTER_COUNTER_DEC(A,B) G_STMT_START{ (void)0; }G_STMT_END +#define CLUTTER_TIMER_START(A,B) G_STMT_START{ (void)0; }G_STMT_END +#define CLUTTER_TIMER_STOP(A,B) G_STMT_START{ (void)0; }G_STMT_END + +#endif /* CLUTTER_ENABLE_PROFILE */ + +G_END_DECLS + +#endif /* _CLUTTER_PROFILE_H_ */ diff --git a/clutter/clutter-stage.c b/clutter/clutter-stage.c index 32eac253f..66b7d0eba 100644 --- a/clutter/clutter-stage.c +++ b/clutter/clutter-stage.c @@ -68,6 +68,7 @@ #include "clutter-version.h" /* For flavour */ #include "clutter-id-pool.h" #include "clutter-container.h" +#include "clutter-profile.h" #include "cogl/cogl.h" @@ -246,6 +247,11 @@ clutter_stage_paint (ClutterActor *self) ClutterStagePrivate *priv = CLUTTER_STAGE (self)->priv; CoglColor stage_color; guint8 real_alpha; + CLUTTER_STATIC_TIMER (stage_clear_timer, + "Painting actors", /* parent */ + "Stage clear", + "The time spent clearing the stage", + 0 /* no application private data */); CLUTTER_NOTE (PAINT, "Initializing stage paint"); @@ -264,9 +270,12 @@ clutter_stage_paint (ClutterActor *self) priv->use_alpha ? real_alpha : 255); cogl_color_premultiply (&stage_color); + + CLUTTER_TIMER_START (_clutter_uprof_context, stage_clear_timer); cogl_clear (&stage_color, COGL_BUFFER_BIT_COLOR | COGL_BUFFER_BIT_DEPTH); + CLUTTER_TIMER_STOP (_clutter_uprof_context, stage_clear_timer); if (priv->use_fog) { diff --git a/clutter/glx/clutter-backend-glx.c b/clutter/glx/clutter-backend-glx.c index dfcf9ee32..7d8d417b9 100644 --- a/clutter/glx/clutter-backend-glx.c +++ b/clutter/glx/clutter-backend-glx.c @@ -42,6 +42,7 @@ #include "clutter-backend-glx.h" #include "clutter-stage-glx.h" #include "clutter-glx.h" +#include "clutter-profile.h" #include "../clutter-event.h" #include "../clutter-main.h" @@ -51,6 +52,7 @@ #include "cogl/cogl.h" + G_DEFINE_TYPE (ClutterBackendGLX, clutter_backend_glx, CLUTTER_TYPE_BACKEND_X11); /* singleton object */ @@ -654,6 +656,16 @@ clutter_backend_glx_redraw (ClutterBackend *backend, ClutterStageGLX *stage_glx; ClutterStageX11 *stage_x11; ClutterStageWindow *impl; + CLUTTER_STATIC_TIMER (painting_timer, + "Redrawing", /* parent */ + "Painting actors", + "The time spent painting actors", + 0 /* no application private data */); + CLUTTER_STATIC_TIMER (swapbuffers_timer, + "Redrawing", /* parent */ + "glXSwapBuffers", + "The time spent blocked by glXSwapBuffers", + 0 /* no application private data */); impl = _clutter_stage_get_window (stage); if (G_UNLIKELY (impl == NULL)) @@ -668,9 +680,11 @@ clutter_backend_glx_redraw (ClutterBackend *backend, stage_x11 = CLUTTER_STAGE_X11 (impl); stage_glx = CLUTTER_STAGE_GLX (impl); + CLUTTER_TIMER_START (_clutter_uprof_context, painting_timer); /* this will cause the stage implementation to be painted */ clutter_actor_paint (CLUTTER_ACTOR (stage)); cogl_flush (); + CLUTTER_TIMER_STOP (_clutter_uprof_context, painting_timer); if (stage_x11->xwin != None) { @@ -682,7 +696,10 @@ clutter_backend_glx_redraw (ClutterBackend *backend, CLUTTER_NOTE (BACKEND, "glXSwapBuffers (display: %p, window: 0x%lx)", backend_x11->xdpy, (unsigned long) stage_x11->xwin); + + CLUTTER_TIMER_START (_clutter_uprof_context, swapbuffers_timer); glXSwapBuffers (backend_x11->xdpy, stage_x11->xwin); + CLUTTER_TIMER_STOP (_clutter_uprof_context, swapbuffers_timer); } }