bug 606574 - Implement event loop instrumentation using native events, core implementation + GTK2 implementation. r=karlt,cjones

config/autoconf.mk.in

@@ -716,6 +716,8 @@ ANDROID_PACKAGE_NAME = @ANDROID_PACKAGE_NAME@
 
 JS_SHARED_LIBRARY = @JS_SHARED_LIBRARY@
 
+MOZ_INSTRUMENT_EVENT_LOOP = @MOZ_INSTRUMENT_EVENT_LOOP@
+
 # We only want to do the pymake sanity on Windows, other os's can cope
 ifeq (,$(filter-out WINNT WINCE,$(HOST_OS_ARCH)))
 # Ensure invariants between GNU Make and pymake

configure.in

@@ -5220,6 +5220,7 @@ cairo-gtk2|cairo-gtk2-x11)
     TK_LIBS='$(MOZ_GTK2_LIBS)'
     AC_DEFINE(MOZ_WIDGET_GTK2)
     MOZ_PDF_PRINTING=1
+    MOZ_INSTRUMENT_EVENT_LOOP=1
     ;;
 
 cairo-gtk2-dfb)
@@ -5302,6 +5303,10 @@ if test "$MOZ_ENABLE_XREMOTE"; then
     AC_DEFINE(MOZ_ENABLE_XREMOTE)
 fi
 
+if test "$MOZ_INSTRUMENT_EVENT_LOOP"; then
+   AC_DEFINE(MOZ_INSTRUMENT_EVENT_LOOP)
+fi
+
 if test "$COMPILE_ENVIRONMENT"; then
   if test "$MOZ_ENABLE_GTK2"; then
     if test "$MOZ_X11"; then
@@ -9185,6 +9190,7 @@ AC_SUBST(VPX_AS_CONVERSION)
 AC_SUBST(VPX_ASM_SUFFIX)
 AC_SUBST(VPX_X86_ASM)
 AC_SUBST(VPX_ARM_ASM)
+AC_SUBST(MOZ_INSTRUMENT_EVENT_LOOP)
 AC_SUBST(LIBJPEG_TURBO_AS)
 AC_SUBST(LIBJPEG_TURBO_ASFLAGS)
 AC_SUBST(LIBJPEG_TURBO_X86_ASM)

toolkit/xre/EventTracer.cpp

@@ -0,0 +1,182 @@
+/* ***** BEGIN LICENSE BLOCK *****
+ * Version: MPL 1.1/GPL 2.0/LGPL 2.1
+ *
+ * The contents of this file are subject to the Mozilla Public License Version
+ * 1.1 (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ * http://www.mozilla.org/MPL/
+ *
+ * Software distributed under the License is distributed on an "AS IS" basis,
+ * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
+ * for the specific language governing rights and limitations under the
+ * License.
+ *
+ * The Original Code is mozilla.org code.
+ *
+ * The Initial Developer of the Original Code is
+ * The Mozilla Foundation.
+ * Portions created by the Initial Developer are Copyright (C) 2011
+ * the Initial Developer. All Rights Reserved.
+ *
+ * Contributor(s):
+ *   Ted Mielczarek <ted.mielczarek@gmail.com>
+ *
+ * Alternatively, the contents of this file may be used under the terms of
+ * either the GNU General Public License Version 2 or later (the "GPL"), or
+ * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
+ * in which case the provisions of the GPL or the LGPL are applicable instead
+ * of those above. If you wish to allow use of your version of this file only
+ * under the terms of either the GPL or the LGPL, and not to allow others to
+ * use your version of this file under the terms of the MPL, indicate your
+ * decision by deleting the provisions above and replace them with the notice
+ * and other provisions required by the GPL or the LGPL. If you do not delete
+ * the provisions above, a recipient may use your version of this file under
+ * the terms of any one of the MPL, the GPL or the LGPL.
+ *
+ * ***** END LICENSE BLOCK ***** */
+
+/*
+ * Event loop instrumentation. This code attempts to measure the
+ * latency of the UI-thread event loop by firing native events at it from
+ * a background thread, and measuring how long it takes for them
+ * to be serviced. The measurement interval (kMeasureInterval, below)
+ * is also used as the upper bound of acceptable response time.
+ * When an event takes longer than that interval to be serviced,
+ * a sample will be written to the log.
+ *
+ * Usage:
+ *
+ * Set MOZ_INSTRUMENT_EVENT_LOOP=1 in the environment to enable
+ * this instrumentation. Currently only the UI process is instrumented.
+ *
+ * Set MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT in the environment to a
+ * file path to contain the log output, the default is to log to stdout.
+ *
+ * All logged output lines start with MOZ_EVENT_TRACE. All timestamps
+ * output are milliseconds since the epoch (PRTime / 1000).
+ *
+ * On startup, a line of the form:
+ *   MOZ_EVENT_TRACE start <timestamp>
+ * will be output.
+ *
+ * On shutdown, a line of the form:
+ *   MOZ_EVENT_TRACE stop <timestamp>
+ * will be output.
+ *
+ * When an event servicing time exceeds the threshold, a line of the form:
+ *   MOZ_EVENT_TRACE sample <timestamp> <duration>
+ * will be output, where <duration> is the number of milliseconds that
+ * it took for the event to be serviced.
+ */
+
+#include "EventTracer.h"
+
+#include <stdio.h>
+
+#include "mozilla/TimeStamp.h"
+#include "mozilla/WidgetTraceEvent.h"
+#include <prenv.h>
+#include <prinrval.h>
+#include <prthread.h>
+#include <prtime.h>
+
+using mozilla::TimeDuration;
+using mozilla::TimeStamp;
+using mozilla::FireAndWaitForTracerEvent;
+
+namespace {
+
+PRThread* sTracerThread = NULL;
+bool sExit = false;
+
+/*
+ * The tracer thread fires events at the native event loop roughly
+ * every kMeasureInterval. It will sleep to attempt not to send them
+ * more quickly, but if the response time is longer than kMeasureInterval
+ * it will not send another event until the previous response is received.
+ *
+ * The output defaults to stdout, but can be redirected to a file by
+ * settting the environment variable MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT
+ * to the name of a file to use.
+ */
+void TracerThread(void *arg)
+{
+  // This should be set to the maximum latency we'd like to allow
+  // for responsiveness.
+  const PRIntervalTime kMeasureInterval = PR_MillisecondsToInterval(50);
+
+  FILE* log = NULL;
+  char* envfile = PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP_OUTPUT");
+  if (envfile) {
+    log = fopen(envfile, "w");
+  }
+  if (log == NULL)
+    log = stdout;
+
+  fprintf(log, "MOZ_EVENT_TRACE start %llu\n", PR_Now() / PR_USEC_PER_MSEC);
+
+  while (!sExit) {
+    TimeStamp start(TimeStamp::Now());
+    PRIntervalTime next_sleep = kMeasureInterval;
+
+    //TODO: only wait up to a maximum of kMeasureInterval, return
+    // early if that threshold is exceeded and dump a stack trace
+    // or do something else useful.
+    if (FireAndWaitForTracerEvent()) {
+      TimeDuration duration = TimeStamp::Now() - start;
+      // Only report samples that exceed our measurement interval.
+      if (duration.ToMilliseconds() > kMeasureInterval) {
+        fprintf(log, "MOZ_EVENT_TRACE sample %llu %d\n",
+                PR_Now() / PR_USEC_PER_MSEC,
+                int(duration.ToSecondsSigDigits() * 1000));
+      }
+
+      if (next_sleep > duration.ToMilliseconds()) {
+        next_sleep -= int(duration.ToMilliseconds());
+      }
+      else {
+        // Don't sleep at all if this event took longer than the measure
+        // interval to deliver.
+        next_sleep = 0;
+      }
+    }
+
+    if (next_sleep != 0 && !sExit) {
+      PR_Sleep(next_sleep);
+    }
+  }
+
+  fprintf(log, "MOZ_EVENT_TRACE stop %llu\n", PR_Now() / PR_USEC_PER_MSEC);
+
+  if (log != stdout)
+    fclose(log);
+}
+
+} // namespace
+
+namespace mozilla {
+
+bool InitEventTracing()
+{
+  // Create a thread that will fire events back at the
+  // main thread to measure responsiveness.
+  NS_ABORT_IF_FALSE(!sTracerThread, "Event tracing already initialized!");
+  sTracerThread = PR_CreateThread(PR_USER_THREAD,
+                                  TracerThread,
+                                  NULL,
+                                  PR_PRIORITY_NORMAL,
+                                  PR_GLOBAL_THREAD,
+                                  PR_JOINABLE_THREAD,
+                                  0);
+  return sTracerThread != NULL;
+}
+
+void ShutdownEventTracing()
+{
+  sExit = true;
+  if (sTracerThread)
+    PR_JoinThread(sTracerThread);
+  sTracerThread = NULL;
+}
+
+}  // namespace mozilla

toolkit/xre/EventTracer.h

@@ -0,0 +1,54 @@
+/* ***** BEGIN LICENSE BLOCK *****
+ * Version: MPL 1.1/GPL 2.0/LGPL 2.1
+ *
+ * The contents of this file are subject to the Mozilla Public License Version
+ * 1.1 (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ * http://www.mozilla.org/MPL/
+ *
+ * Software distributed under the License is distributed on an "AS IS" basis,
+ * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
+ * for the specific language governing rights and limitations under the
+ * License.
+ *
+ * The Original Code is mozilla.org code.
+ *
+ * The Initial Developer of the Original Code is
+ * The Mozilla Foundation.
+ * Portions created by the Initial Developer are Copyright (C) 2011
+ * the Initial Developer. All Rights Reserved.
+ *
+ * Contributor(s):
+ *   Ted Mielczarek <ted.mielczarek@gmail.com>
+ *
+ * Alternatively, the contents of this file may be used under the terms of
+ * either the GNU General Public License Version 2 or later (the "GPL"), or
+ * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
+ * in which case the provisions of the GPL or the LGPL are applicable instead
+ * of those above. If you wish to allow use of your version of this file only
+ * under the terms of either the GPL or the LGPL, and not to allow others to
+ * use your version of this file under the terms of the MPL, indicate your
+ * decision by deleting the provisions above and replace them with the notice
+ * and other provisions required by the GPL or the LGPL. If you do not delete
+ * the provisions above, a recipient may use your version of this file under
+ * the terms of any one of the MPL, the GPL or the LGPL.
+ *
+ * ***** END LICENSE BLOCK ***** */
+
+#ifndef XRE_EVENTTRACER_H_
+#define XRE_EVENTTRACER_H_
+
+namespace mozilla {
+
+// Create a thread that will fire events back at the
+// main thread to measure responsiveness. Return true
+// if the thread was created successfully.
+bool InitEventTracing();
+
+// Signal the background thread to stop, and join it.
+// Must be called from the same thread that called InitEventTracing.
+void ShutdownEventTracing();
+
+}  // namespace mozilla
+
+#endif /* XRE_EVENTTRACER_H_ */

toolkit/xre/Makefile.in

@@ -66,6 +66,10 @@ CPPSRCS = \
   nsSigHandlers.cpp \
   $(NULL)
 
+ifdef MOZ_INSTRUMENT_EVENT_LOOP
+CPPSRCS += EventTracer.cpp
+endif
+
 ifdef MOZ_SPLASHSCREEN
 ifeq ($(OS_ARCH),WINCE)
 CPPSRCS += nsSplashScreenWin.cpp

toolkit/xre/nsAppRunner.cpp

@@ -62,6 +62,10 @@ using mozilla::dom::ContentParent;
 #include "nsAppRunner.h"
 #include "nsUpdateDriver.h"
 
+#ifdef MOZ_INSTRUMENT_EVENT_LOOP
+#include "EventTracer.h"
+#endif
+
 #ifdef XP_MACOSX
 #include "MacLaunchHelper.h"
 #include "MacApplicationDelegate.h"
@@ -3744,6 +3748,13 @@ XRE_main(int argc, char* argv[], const nsXREAppData* aAppData)
           nativeApp->Enable();
         }
 
+#ifdef MOZ_INSTRUMENT_EVENT_LOOP
+        bool event_tracing_running = false;
+        if (PR_GetEnv("MOZ_INSTRUMENT_EVENT_LOOP")) {
+          event_tracing_running = mozilla::InitEventTracing();
+        }
+#endif /* MOZ_INSTRUMENT_EVENT_LOOP */
+
         NS_TIME_FUNCTION_MARK("Next: Run");
 
         NS_TIME_FUNCTION_MARK("appStartup->Run");
@@ -3763,6 +3774,11 @@ XRE_main(int argc, char* argv[], const nsXREAppData* aAppData)
 
         NS_TIME_FUNCTION_MARK("appStartup->Run done");
 
+#ifdef MOZ_INSTRUMENT_EVENT_LOOP
+        if (event_tracing_running)
+          mozilla::ShutdownEventTracing();
+#endif
+
         // Check for an application initiated restart.  This is one that
         // corresponds to nsIAppStartup.quit(eRestart)
         if (rv == NS_SUCCESS_RESTART_APP)

widget/public/Makefile.in

@@ -46,12 +46,17 @@ MODULE		= widget
 XPIDL_MODULE	= widget
 GRE_MODULE	= 1
 
-EXPORTS_NAMESPACES = IPC
+EXPORTS_NAMESPACES = IPC mozilla
 
 EXPORTS_IPC = \
 		nsGUIEventIPC.h \
 		$(NULL)
 
+ifdef MOZ_INSTRUMENT_EVENT_LOOP
+EXPORTS_mozilla = \
+  WidgetTraceEvent.h
+endif
+
 EXPORTS		= \
 		nsIWidget.h \
 		nsGUIEvent.h \

widget/public/WidgetTraceEvent.h

@@ -0,0 +1,50 @@
+/* ***** BEGIN LICENSE BLOCK *****
+ * Version: MPL 1.1/GPL 2.0/LGPL 2.1
+ *
+ * The contents of this file are subject to the Mozilla Public License Version
+ * 1.1 (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ * http://www.mozilla.org/MPL/
+ *
+ * Software distributed under the License is distributed on an "AS IS" basis,
+ * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
+ * for the specific language governing rights and limitations under the
+ * License.
+ *
+ * The Original Code is mozilla.org code.
+ *
+ * The Initial Developer of the Original Code is
+ * The Mozilla Foundation.
+ * Portions created by the Initial Developer are Copyright (C) 2011
+ * the Initial Developer. All Rights Reserved.
+ *
+ * Contributor(s):
+ *   Ted Mielczarek <ted.mielczarek@gmail.com>
+ *
+ * Alternatively, the contents of this file may be used under the terms of
+ * either the GNU General Public License Version 2 or later (the "GPL"), or
+ * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
+ * in which case the provisions of the GPL or the LGPL are applicable instead
+ * of those above. If you wish to allow use of your version of this file only
+ * under the terms of either the GPL or the LGPL, and not to allow others to
+ * use your version of this file under the terms of the MPL, indicate your
+ * decision by deleting the provisions above and replace them with the notice
+ * and other provisions required by the GPL or the LGPL. If you do not delete
+ * the provisions above, a recipient may use your version of this file under
+ * the terms of any one of the MPL, the GPL or the LGPL.
+ *
+ * ***** END LICENSE BLOCK ***** */
+
+#ifndef WIDGET_PUBLIC_WIDGETTRACEEVENT_H_
+#define WIDGET_PUBLIC_WIDGETTRACEEVENT_H_
+
+namespace mozilla {
+
+// Fire a tracer event at the UI-thread event loop, and block until
+// the event is processed. This should only be called by
+// a thread that's not the UI thread.
+bool FireAndWaitForTracerEvent();
+
+}
+
+#endif  // WIDGET_PUBLIC_WIDGETTRACEEVENT_H_

widget/src/gtk2/Makefile.in

@@ -78,6 +78,7 @@ CPPSRCS		= \
   nsImageToPixbuf.cpp \
   nsAccessibilityHelper.cpp \
   nsGtkIMModule.cpp \
+  WidgetTraceEvent.cpp \
   $(NULL)
 
 ifdef MOZ_X11

widget/src/gtk2/WidgetTraceEvent.cpp

@@ -0,0 +1,86 @@
+/* ***** BEGIN LICENSE BLOCK *****
+ * Version: MPL 1.1/GPL 2.0/LGPL 2.1
+ *
+ * The contents of this file are subject to the Mozilla Public License Version
+ * 1.1 (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ * http://www.mozilla.org/MPL/
+ *
+ * Software distributed under the License is distributed on an "AS IS" basis,
+ * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
+ * for the specific language governing rights and limitations under the
+ * License.
+ *
+ * The Original Code is mozilla.org code.
+ *
+ * The Initial Developer of the Original Code is
+ * The Mozilla Foundation.
+ * Portions created by the Initial Developer are Copyright (C) 2011
+ * the Initial Developer. All Rights Reserved.
+ *
+ * Contributor(s):
+ *   Ted Mielczarek <ted.mielczarek@gmail.com>
+ *
+ * Alternatively, the contents of this file may be used under the terms of
+ * either the GNU General Public License Version 2 or later (the "GPL"), or
+ * the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
+ * in which case the provisions of the GPL or the LGPL are applicable instead
+ * of those above. If you wish to allow use of your version of this file only
+ * under the terms of either the GPL or the LGPL, and not to allow others to
+ * use your version of this file under the terms of the MPL, indicate your
+ * decision by deleting the provisions above and replace them with the notice
+ * and other provisions required by the GPL or the LGPL. If you do not delete
+ * the provisions above, a recipient may use your version of this file under
+ * the terms of any one of the MPL, the GPL or the LGPL.
+ *
+ * ***** END LICENSE BLOCK ***** */
+
+#include "mozilla/WidgetTraceEvent.h"
+
+#include <glib.h>
+#include <mozilla/CondVar.h>
+#include <mozilla/Mutex.h>
+#include <stdio.h>
+
+using mozilla::CondVar;
+using mozilla::Mutex;
+using mozilla::MutexAutoLock;
+
+namespace {
+
+Mutex sMutex("Event tracer thread mutex");
+CondVar sCondVar(sMutex, "Event tracer thread condvar");
+bool sTracerProcessed = false;
+
+// This function is called from the main (UI) thread.
+gboolean TracerCallback(gpointer data)
+{
+  MutexAutoLock lock(sMutex);
+  NS_ABORT_IF_FALSE(!sTracerProcessed, "Tracer synchronization state is wrong");
+  sTracerProcessed = true;
+  sCondVar.Notify();
+  return FALSE;
+}
+
+} // namespace
+
+namespace mozilla {
+
+// This function is called from the background tracer thread.
+bool FireAndWaitForTracerEvent()
+{
+  // Send a default-priority idle event through the
+  // event loop, and wait for it to finish.
+  MutexAutoLock lock(sMutex);
+  NS_ABORT_IF_FALSE(!sTracerProcessed, "Tracer synchronization state is wrong");
+  g_idle_add_full(G_PRIORITY_DEFAULT,
+                  TracerCallback,
+                  NULL,
+                  NULL);
+  while (!sTracerProcessed)
+    sCondVar.Wait();
+  sTracerProcessed = false;
+  return true;
+}
+
+}  // namespace mozilla