From 56b8d1dfbe7546d8b1363fa3d4af22b090aad37d Mon Sep 17 00:00:00 2001 From: Matthias Clasen Date: Wed, 22 Jan 2020 16:36:02 -0500 Subject: [PATCH] frame clock: Redo the profiler marks Instead of reporting the frame clock phases as defined, report the duration of the signal emissions, which is more useful for tracking down what is taking time. --- gdk/gdkframeclock.c | 52 ++++++++++++++++++++++++++++++++++++++++- gdk/gdkframeclockidle.c | 6 +---- 2 files changed, 52 insertions(+), 6 deletions(-) diff --git a/gdk/gdkframeclock.c b/gdk/gdkframeclock.c index cf3ae0b16d..9626a9f3d2 100644 --- a/gdk/gdkframeclock.c +++ b/gdk/gdkframeclock.c @@ -649,43 +649,92 @@ gdk_frame_clock_get_refresh_info (GdkFrameClock *frame_clock, void _gdk_frame_clock_emit_flush_events (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[FLUSH_EVENTS], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::flush-events", ""); } void _gdk_frame_clock_emit_before_paint (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[BEFORE_PAINT], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::before-paint", ""); } void _gdk_frame_clock_emit_update (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[UPDATE], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::update", ""); } void _gdk_frame_clock_emit_layout (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[LAYOUT], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::layout", ""); } void _gdk_frame_clock_emit_paint (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[PAINT], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::paint", ""); } void _gdk_frame_clock_emit_after_paint (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[AFTER_PAINT], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::after-paint", ""); } void _gdk_frame_clock_emit_resume_events (GdkFrameClock *frame_clock) { + guint64 before = g_get_monotonic_time (); + g_signal_emit (frame_clock, signals[RESUME_EVENTS], 0); + + if (gdk_profiler_is_running ()) + gdk_profiler_add_mark (before * 1000, + (g_get_monotonic_time () - before) * 1000, + "frameclock ::resume-events", ""); } #ifdef G_ENABLE_DEBUG @@ -765,6 +814,7 @@ _gdk_frame_clock_add_timings_to_profiler (GdkFrameClock *clock, GdkFrameTimings *timings) { #ifdef G_ENABLE_DEBUG +#if 0 gdk_profiler_add_mark (timings->frame_time * 1000, (timings->frame_end_time - timings->frame_time) * 1000, "frame", ""); @@ -778,7 +828,7 @@ _gdk_frame_clock_add_timings_to_profiler (GdkFrameClock *clock, gdk_profiler_add_mark (timings->paint_start_time * 1000, (timings->frame_end_time - timings->paint_start_time) * 1000, "paint", ""); - +#endif if (timings->presentation_time != 0) gdk_profiler_add_mark (timings->presentation_time * 1000, 0, diff --git a/gdk/gdkframeclockidle.c b/gdk/gdkframeclockidle.c index 92f5449f93..f5af719cc1 100644 --- a/gdk/gdkframeclockidle.c +++ b/gdk/gdkframeclockidle.c @@ -408,14 +408,12 @@ gdk_frame_clock_paint_idle (void *data) if (priv->freeze_count == 0) { int iter; -#ifdef G_ENABLE_DEBUG if (GDK_DEBUG_CHECK (FRAMES) || gdk_profiler_is_running ()) { if (priv->phase != GDK_FRAME_CLOCK_PHASE_LAYOUT && (priv->requested & GDK_FRAME_CLOCK_PHASE_LAYOUT)) timings->layout_start_time = g_get_monotonic_time (); } -#endif /* G_ENABLE_DEBUG */ priv->phase = GDK_FRAME_CLOCK_PHASE_LAYOUT; /* We loop in the layout phase, because we don't want to progress @@ -438,14 +436,12 @@ gdk_frame_clock_paint_idle (void *data) case GDK_FRAME_CLOCK_PHASE_PAINT: if (priv->freeze_count == 0) { -#ifdef G_ENABLE_DEBUG if (GDK_DEBUG_CHECK (FRAMES) || gdk_profiler_is_running ()) { if (priv->phase != GDK_FRAME_CLOCK_PHASE_PAINT && (priv->requested & GDK_FRAME_CLOCK_PHASE_PAINT)) timings->paint_start_time = g_get_monotonic_time (); } -#endif /* G_ENABLE_DEBUG */ priv->phase = GDK_FRAME_CLOCK_PHASE_PAINT; if (priv->requested & GDK_FRAME_CLOCK_PHASE_PAINT) @@ -602,7 +598,7 @@ gdk_frame_clock_idle_thaw (GdkFrameClock *clock) gint64 thaw_time = g_get_monotonic_time (); gdk_profiler_add_mark (priv->freeze_time * 1000, (thaw_time - priv->freeze_time) * 1000, - "freeze", ""); + "frameclock freeze", ""); priv->freeze_time = 0; } }