From caeb7fce10e4997da503b3cea85722e83d64f6c1 Mon Sep 17 00:00:00 2001 From: mental Date: Tue, 8 Jul 2008 19:16:01 +0000 Subject: [PATCH] instrument event latency --- src/debug/CMakeLists.txt | 1 + src/debug/Makefile_insert | 1 + src/debug/gdk-event-latency-tracker.cpp | 65 +++++++++++++++++++++++++ src/debug/gdk-event-latency-tracker.h | 52 ++++++++++++++++++++ src/display/sp-canvas.cpp | 14 ++++++ 5 files changed, 133 insertions(+) create mode 100644 src/debug/gdk-event-latency-tracker.cpp create mode 100644 src/debug/gdk-event-latency-tracker.h diff --git a/src/debug/CMakeLists.txt b/src/debug/CMakeLists.txt index 88c8b8e29..5eb0b3cfe 100644 --- a/src/debug/CMakeLists.txt +++ b/src/debug/CMakeLists.txt @@ -5,5 +5,6 @@ log-display-config.cpp logger.cpp sysv-heap.cpp timestamp.cpp +gdk-event-latency-tracker.cpp ) diff --git a/src/debug/Makefile_insert b/src/debug/Makefile_insert index 96a12f3f4..699ceac84 100644 --- a/src/debug/Makefile_insert +++ b/src/debug/Makefile_insert @@ -14,5 +14,6 @@ debug_libinkdebug_a_SOURCES = \ debug/log-display-config.cpp debug/log-display-config.h \ debug/simple-event.h \ debug/sysv-heap.cpp debug/sysv-heap.h \ + debug/gdk-event-latency-tracker.cpp debug/gdk-event-latency-tracker.h \ debug/timestamp.cpp debug/timestamp.h diff --git a/src/debug/gdk-event-latency-tracker.cpp b/src/debug/gdk-event-latency-tracker.cpp new file mode 100644 index 000000000..8e34d2fc2 --- /dev/null +++ b/src/debug/gdk-event-latency-tracker.cpp @@ -0,0 +1,65 @@ +/* + * Inkscape::Debug::GdkEventLatencyTracker - tracks backlog of GDK events + * + * Authors: + * MenTaLguY + * + * Copyright (C) 2008 MenTaLguY + * + * Released under GNU GPL, read the file 'COPYING' for more information + */ + +#include "debug/gdk-event-latency-tracker.h" + +namespace Inkscape { +namespace Debug { + +GdkEventLatencyTracker::GdkEventLatencyTracker() +: start_seconds(0.0), max_latency(0.0) +{ + elapsed.stop(); + elapsed.reset(); +} + +boost::optional GdkEventLatencyTracker::process(GdkEvent const *event) { + guint32 const timestamp=gdk_event_get_time(const_cast(event)); + if (timestamp == GDK_CURRENT_TIME) { + return boost::optional(); + } + double const timestamp_seconds = timestamp / 1000.0; + + if (start_seconds == 0.0) { + elapsed.start(); + start_seconds = timestamp_seconds; + return boost::optional(0.0); + } else { + double const current_seconds = elapsed.elapsed() + start_seconds; + double delta = current_seconds - timestamp_seconds; + if (delta < 0.0) { + start_seconds += -delta; + delta = 0.0; + } else if (delta > max_latency) { + max_latency = delta; + } + return boost::optional(delta); + } +} + +GdkEventLatencyTracker &GdkEventLatencyTracker::default_tracker() { + static GdkEventLatencyTracker tracker; + return tracker; +} + +} +} + +/* + Local Variables: + mode:c++ + c-file-style:"stroustrup" + c-file-offsets:((innamespace . 0)(inline-open . 0)(case-label . +)) + indent-tabs-mode:nil + fill-column:99 + End: +*/ +// vim: filetype=cpp:expandtab:shiftwidth=4:tabstop=8:softtabstop=4:encoding=utf-8:textwidth=99 : diff --git a/src/debug/gdk-event-latency-tracker.h b/src/debug/gdk-event-latency-tracker.h new file mode 100644 index 000000000..8a22fec82 --- /dev/null +++ b/src/debug/gdk-event-latency-tracker.h @@ -0,0 +1,52 @@ +/* + * Inkscape::Debug::GdkEventLatencyTracker - tracks backlog of GDK events + * + * Authors: + * MenTaLguY + * + * Copyright (C) 2008 MenTaLguY + * + * Released under GNU GPL, read the file 'COPYING' for more information + */ + +#ifndef SEEN_INKSCAPE_DEBUG_GDK_EVENT_LATENCY_TRACKER_H +#define SEEN_INKSCAPE_DEBUG_GDK_EVENT_LATENCY_TRACKER_H + +#include +#include +#include + +namespace Inkscape { +namespace Debug { + +class GdkEventLatencyTracker { +public: + GdkEventLatencyTracker(); + boost::optional process(GdkEvent const *e); + double maxLatency() const { return max_latency; } + + static GdkEventLatencyTracker &default_tracker(); + +private: + GdkEventLatencyTracker(GdkEventLatencyTracker const &); // no copy + void operator=(GdkEventLatencyTracker const &); // no assign + + double start_seconds; + double max_latency; + Glib::Timer elapsed; +}; + +} +} + +#endif +/* + Local Variables: + mode:c++ + c-file-style:"stroustrup" + c-file-offsets:((innamespace . 0)(inline-open . 0)(case-label . +)) + indent-tabs-mode:nil + fill-column:99 + End: +*/ +// vim: filetype=cpp:expandtab:shiftwidth=4:tabstop=8:softtabstop=4:encoding=utf-8:textwidth=99 : diff --git a/src/display/sp-canvas.cpp b/src/display/sp-canvas.cpp index def126cd3..3d63d7cdd 100644 --- a/src/display/sp-canvas.cpp +++ b/src/display/sp-canvas.cpp @@ -43,6 +43,9 @@ #include "display/rendermode.h" #include "libnr/nr-blit.h" #include "display/inkscape-cairo.h" +#include "debug/gdk-event-latency-tracker.h" + +using Inkscape::Debug::GdkEventLatencyTracker; // GTK_CHECK_VERSION returns false on failure #define HAS_GDK_EVENT_REQUEST_MOTIONS GTK_CHECK_VERSION(2, 12, 0) @@ -102,6 +105,7 @@ enum {ITEM_EVENT, ITEM_LAST_SIGNAL}; static void sp_canvas_request_update (SPCanvas *canvas); +static void track_latency(GdkEvent const *event); static void sp_canvas_item_class_init (SPCanvasItemClass *klass); static void sp_canvas_item_init (SPCanvasItem *item); static void sp_canvas_item_dispose (GObject *object); @@ -1097,6 +1101,14 @@ sp_canvas_destroy (GtkObject *object) (* GTK_OBJECT_CLASS (canvas_parent_class)->destroy) (object); } +static void track_latency(GdkEvent const *event) { + GdkEventLatencyTracker &tracker = GdkEventLatencyTracker::default_tracker(); + boost::optional latency = tracker.process(event); + if (latency && *latency > 2.0) { + g_warning("Event latency reached %f sec", *latency); + } +} + /** * Returns new canvas as widget. */ @@ -1564,6 +1576,8 @@ sp_canvas_motion (GtkWidget *widget, GdkEventMotion *event) int status; SPCanvas *canvas = SP_CANVAS (widget); + track_latency((GdkEvent *)event); + if (event->window != SP_CANVAS_WINDOW (canvas)) return FALSE; -- 2.30.2