Bug 729182 - Implement visual event tracer, part1 - the core, r=benjamin+ehsan
authorHonza Bambas <honzab.moz@firemni.cz>
Tue, 12 Jun 2012 19:06:21 +0200
changeset 101294 22796d93c42e7b8b872adfee86af3945816aac2e
parent 101293 772d9d20cdf913568c154a6387d784a3c36dc622
child 101295 7beb4319143785785edd6196f3a0519583c39b61
push idunknown
push userunknown
push dateunknown
reviewersbenjamin
bugs729182
milestone16.0a1
Bug 729182 - Implement visual event tracer, part1 - the core, r=benjamin+ehsan
configure.in
xpcom/base/Makefile.in
xpcom/base/VisualEventTracer.cpp
xpcom/base/VisualEventTracer.h
xpcom/build/nsXPComInit.cpp
--- a/configure.in
+++ b/configure.in
@@ -7394,16 +7394,27 @@ MOZ_ARG_ENABLE_BOOL(functiontimer,
 [  --enable-functiontimer  Enable NS_FUNCTION_TIMER ],
     NS_FUNCTION_TIMER=1,
     NS_FUNCTION_TIMER= )
 if test -n "$NS_FUNCTION_TIMER"; then
     AC_DEFINE(NS_FUNCTION_TIMER)
 fi
 
 dnl ========================================================
+dnl = Enable runtime visual profiling logger
+dnl ========================================================
+MOZ_ARG_ENABLE_BOOL(visual-event-tracer,
+[  --enable-visual-event-tracer   Enable visual event tracer instrumentation],
+    MOZ_VISUAL_EVENT_TRACER=1,
+    MOZ_VISUAL_EVENT_TRACER=)
+if test -n "$MOZ_VISUAL_EVENT_TRACER"; then
+    AC_DEFINE(MOZ_VISUAL_EVENT_TRACER)
+fi
+
+dnl ========================================================
 dnl Turn on reflow counting
 dnl ========================================================
 MOZ_ARG_ENABLE_BOOL(reflow-perf,
 [  --enable-reflow-perf    Enable reflow performance tracing],
     MOZ_REFLOW_PERF=1,
     MOZ_REFLOW_PERF= )
 if test -n "$MOZ_REFLOW_PERF"; then
     AC_DEFINE(MOZ_REFLOW_PERF)
--- a/xpcom/base/Makefile.in
+++ b/xpcom/base/Makefile.in
@@ -34,16 +34,17 @@ CPPSRCS		= \
 		nsInterfaceRequestorAgg.cpp \
 		nsUUIDGenerator.cpp \
 		nsSystemInfo.cpp \
 		nsCycleCollector.cpp \
 		nsStackWalk.cpp \
 		nsMemoryReporterManager.cpp \
 		FunctionTimer.cpp \
 		ClearOnShutdown.cpp \
+		VisualEventTracer.cpp \
 		$(NULL)
 
 ifeq ($(OS_ARCH),Linux)
 CPPSRCS += MapsMemoryReporter.cpp
 endif
 
 ifeq (cocoa,$(MOZ_WIDGET_TOOLKIT))
 CPPSRCS		+= nsMacUtilsImpl.cpp
@@ -68,16 +69,17 @@ EXPORTS		= \
 EXPORTS_NAMESPACES = mozilla
 
 EXPORTS_mozilla = \
 	FunctionTimer.h \
 	MapsMemoryReporter.h \
 	ClearOnShutdown.h \
 	AvailableMemoryTracker.h \
 	StackWalk.h \
+	VisualEventTracer.h \
 	$(NULL)
 
 ifeq (windows,$(MOZ_WIDGET_TOOLKIT))
 CPPSRCS += nsCrashOnException.cpp
 endif
 
 ifeq ($(OS_ARCH),WINNT)
 
new file mode 100644
--- /dev/null
+++ b/xpcom/base/VisualEventTracer.cpp
@@ -0,0 +1,462 @@
+/* ***** 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 code.
+ *
+ * The Initial Developer of the Original Code is
+ * Mozilla Foundation.
+ * Portions created by the Initial Developer are Copyright (C) 2012
+ * the Initial Developer. All Rights Reserved.
+ *
+ * Contributor(s):
+ *   Honza Bambas <honzab.moz@firemni.cz>
+ *
+ * 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/VisualEventTracer.h"
+#include "mozilla/Monitor.h"
+#include "mozilla/TimeStamp.h"
+#include "nscore.h"
+#include "prthread.h"
+#include "prprf.h"
+#include "prio.h"
+#include "prenv.h"
+#include "plstr.h"  
+
+namespace mozilla { namespace eventtracer {
+
+#ifdef MOZ_VISUAL_EVENT_TRACER
+
+namespace {
+
+const PRUint32 kBatchSize = 0x1000;
+const char kTypeChars[eventtracer::eLast] = {' ','N','S','W','E','D'};
+
+// Flushing thread and records queue monitor
+mozilla::Monitor * gMonitor = nsnull;
+
+// Accessed concurently but since this flag is not functionally critical
+// for optimization purposes is not accessed under a lock
+bool gInitialized = false;
+
+// Record of a single event
+class Record {
+public:
+  Record() 
+    : mType(::mozilla::eventtracer::eNone)
+    , mTime(0)
+    , mItem(nsnull)
+    , mText(nsnull)
+    , mText2(nsnull) 
+  {
+    MOZ_COUNT_CTOR(Record);
+  } 
+  ~Record() 
+  {
+    PL_strfree(mText); 
+    PL_strfree(mText2);
+    MOZ_COUNT_DTOR(Record);
+  }
+
+  PRUint32 mType;
+  double mTime;
+  void * mItem;
+  char * mText;
+  char * mText2;
+};
+
+// An array of events, each thread keeps its own private instance
+class RecordBatch {
+public:
+  RecordBatch()
+    : mRecordsHead(new Record[kBatchSize])
+    , mRecordsTail(mRecordsHead + kBatchSize)
+    , mNextRecord(mRecordsHead)
+    , mNextBatch(nsnull)
+    , mThreadNameCopy(PL_strdup(PR_GetThreadName(PR_GetCurrentThread())))
+  {
+    MOZ_COUNT_CTOR(RecordBatch);
+  }
+
+  ~RecordBatch()
+  {
+    delete [] mRecordsHead;
+    PL_strfree(mThreadNameCopy);
+    MOZ_COUNT_DTOR(RecordBatch);
+  }
+
+  static void FlushBatch(void * aData);
+
+  Record * mRecordsHead;
+  Record * mRecordsTail;
+  Record * mNextRecord;
+
+  RecordBatch * mNextBatch;
+  char * mThreadNameCopy;
+};
+
+// Protected by gMonitor, accessed concurently
+// Linked list of batches threads want to flush on disk
+RecordBatch * gLogHead = nsnull;
+RecordBatch * gLogTail = nsnull;
+
+// Registered as thread private data destructor
+void
+RecordBatch::FlushBatch(void * aData)
+{
+  RecordBatch * threadLogPrivate = static_cast<RecordBatch *>(aData);
+
+  MonitorAutoLock mon(*gMonitor);
+
+  if (!gInitialized) {
+    delete threadLogPrivate;
+    return;
+  }
+
+  if (!gLogHead)
+    gLogHead = threadLogPrivate;
+  else // gLogTail is non-null
+    gLogTail->mNextBatch = threadLogPrivate;
+  gLogTail = threadLogPrivate;
+
+  mon.Notify();  
+}
+
+// Helper class for filtering events by MOZ_PROFILING_EVENTS
+class EventFilter
+{
+public:
+  static EventFilter * Build(const char * filterVar);
+  bool EventPasses(const char * eventName);
+
+  ~EventFilter()
+  {
+    delete mNext;
+    PL_strfree(mFilter);
+    MOZ_COUNT_DTOR(EventFilter);
+  }
+
+private:
+  EventFilter(const char * eventName, EventFilter * next)
+    : mFilter(PL_strdup(eventName))
+    , mNext(next)
+  {
+    MOZ_COUNT_CTOR(EventFilter);
+  }
+
+  char * mFilter;
+  EventFilter * mNext;
+};
+
+// static
+EventFilter *
+EventFilter::Build(const char * filterVar)
+{
+  if (!filterVar || !*filterVar)
+    return nsnull;
+
+  // Reads a comma serpatated list of events.
+
+  // Copied from nspr logging code (read of NSPR_LOG_MODULES)
+  char eventName[64];
+  PRIntn evlen = strlen(filterVar), pos = 0, count, delta = 0;
+
+  // Read up to a comma or EOF -> get name of an event first in the list
+  count = sscanf(filterVar, "%63[^,]%n", eventName, &delta);
+  if (count == 0) 
+    return nsnull;
+
+  pos = delta;
+
+  // Skip a comma, if present, accept spaces around it
+  count = sscanf(filterVar + pos, " , %n", &delta);
+  if (count != EOF)
+    pos += delta;
+
+  // eventName contains name of the first event in the list
+  // second argument recursively parses the rest of the list string and
+  // fills mNext of the just created EventFilter object chaining the objects
+  return new EventFilter(eventName, Build(filterVar + pos));
+}
+
+bool
+EventFilter::EventPasses(const char * eventName)
+{
+  if (!strcmp(eventName, mFilter))
+    return true;
+
+  if (mNext)
+    return mNext->EventPasses(eventName);
+
+  return false;
+}
+
+// State var to stop the flushing thread
+bool gStopFlushingThread = false;
+
+// State and control variables, initialized in Init() method, after it 
+// immutable and read concurently.
+EventFilter * gEventFilter = nsnull;
+const char * gLogFilePath = nsnull;
+PRThread * gFlushingThread = nsnull;
+PRUintn gThreadPrivateIndex;
+mozilla::TimeStamp gProfilerStart;
+
+// To prevent any major I/O blockade caused by call to eventtracer::Mark() 
+// we buffer the data produced by each thread and write it to disk
+// in a separate low-priority thread.
+
+// static
+void FlushingThread(void * aArg)
+{
+  PRFileDesc * logFile = PR_Open(gLogFilePath, 
+                         PR_WRONLY | PR_TRUNCATE | PR_CREATE_FILE,
+                         0644);
+
+  MonitorAutoLock mon(*gMonitor);
+
+  if (!logFile) {
+    gInitialized = false;
+    return;
+  }
+
+  PRInt32 rv;
+  bool ioError = false;
+
+  const char logHead[] = "{\n\"version\": 1,\n\"records\":[\n";
+  rv = PR_Write(logFile, logHead, sizeof(logHead) - 1);
+  ioError |= (rv < 0);
+
+  bool firstBatch = true;
+  while (!gStopFlushingThread || gLogHead) {
+    if (ioError) {
+      gInitialized = false;
+      break;
+    }
+
+    mon.Wait();
+
+    // Grab the current log list head and start a new blank global list
+    RecordBatch * batch = gLogHead;
+    gLogHead = nsnull;
+    gLogTail = nsnull;
+
+    MonitorAutoUnlock unlock(*gMonitor); // no need to block on I/O :-)
+
+    while (batch) {
+      if (!firstBatch) {
+        const char threadDelimiter[] = ",\n";
+        rv = PR_Write(logFile, threadDelimiter, sizeof(threadDelimiter) - 1);
+        ioError |= (rv < 0);
+      }
+      firstBatch = false;
+
+      static const PRIntn kBufferSize = 2048;
+      char buf[kBufferSize];
+
+      PR_snprintf(buf, kBufferSize, "{\"thread\":\"%s\",\"log\":[\n", 
+                  batch->mThreadNameCopy);
+
+      rv = PR_Write(logFile, buf, strlen(buf));
+      ioError |= (rv < 0);
+
+      for (Record * record = batch->mRecordsHead;
+           record < batch->mNextRecord && !ioError;
+           ++record) {
+
+        // mType carries both type and flags, separate type 
+        // as lower 16 bits and flags as higher 16 bits.
+        // The json format expects this separated.
+        PRUint32 type = record->mType & 0xffffUL;
+        PRUint32 flags = record->mType >> 16;
+        PR_snprintf(buf, kBufferSize, 
+          "{\"e\":\"%c\",\"t\":%f,\"f\":%d,\"i\":\"%p\",\"n\":\"%s%s\"}%s\n",
+          kTypeChars[type],
+          record->mTime,
+          flags,
+          record->mItem,
+          record->mText,
+          record->mText2 ? record->mText2 : "",
+          (record == batch->mNextRecord - 1) ? "" : ",");
+
+        rv = PR_Write(logFile, buf, strlen(buf));
+        ioError |= (rv < 0);
+      }
+
+      const char threadTail[] = "]}\n";
+      rv = PR_Write(logFile, threadTail, sizeof(threadTail) - 1);
+      ioError |= (rv < 0);
+
+      RecordBatch * next = batch->mNextBatch;
+      delete batch;
+      batch = next;
+    }
+  }
+
+  const char logTail[] = "]}\n";
+  rv = PR_Write(logFile, logTail, sizeof(logTail) - 1);
+  ioError |= (rv < 0);
+
+  PR_Close(logFile);
+
+  if (ioError)
+    PR_Delete(gLogFilePath);
+}
+
+// static
+bool CheckEventFilters(PRUint32 aType, void * aItem, const char * aText)
+{
+  if (!gEventFilter)
+    return true;
+
+  if (aType == eName)
+    return true;
+
+  if (aItem == gFlushingThread) // Pass events coming from the tracer
+    return true;
+
+  return gEventFilter->EventPasses(aText);
+}
+
+} // anon namespace
+
+#endif //MOZ_VISUAL_EVENT_TRACER
+
+// static 
+void Init()
+{
+#ifdef MOZ_VISUAL_EVENT_TRACER
+  const char * logFile = PR_GetEnv("MOZ_PROFILING_FILE");
+  if (!logFile || !*logFile)
+    return;
+
+  gLogFilePath = logFile;
+
+  const char * logEvents = PR_GetEnv("MOZ_PROFILING_EVENTS");
+  if (logEvents && *logEvents)
+    gEventFilter = EventFilter::Build(logEvents);
+
+  gProfilerStart = mozilla::TimeStamp::Now();
+
+  PRStatus status = PR_NewThreadPrivateIndex(&gThreadPrivateIndex, 
+                                             &RecordBatch::FlushBatch);
+  if (status != PR_SUCCESS)
+    return;
+
+  gMonitor = new mozilla::Monitor("Profiler");
+  if (!gMonitor)
+    return;
+
+  gFlushingThread = PR_CreateThread(PR_USER_THREAD, 
+                                    &FlushingThread,
+                                    nsnull,
+                                    PR_PRIORITY_LOW,
+                                    PR_LOCAL_THREAD,
+                                    PR_JOINABLE_THREAD,
+                                    32768);
+  if (!gFlushingThread)
+    return;
+    
+  gInitialized = true;
+
+  MOZ_EVENT_TRACER_NAME_OBJECT(gFlushingThread, "Profiler");
+  MOZ_EVENT_TRACER_MARK(gFlushingThread, "Profiling Start");
+#endif
+}
+
+// static 
+void Shutdown()
+{
+#ifdef MOZ_VISUAL_EVENT_TRACER
+  MOZ_EVENT_TRACER_MARK(gFlushingThread, "Profiling End");
+
+  // This must be called after all other threads had been shut down 
+  // (i.e. their private data had been 'released').
+
+  // Release the private data of this thread to flush all the remaning writes.
+  PR_SetThreadPrivate(gThreadPrivateIndex, nsnull);
+
+  if (gFlushingThread) {
+    {
+      MonitorAutoLock mon(*gMonitor);
+      gInitialized = false;
+      gStopFlushingThread = true;
+      mon.Notify();
+    }
+
+    PR_JoinThread(gFlushingThread);
+    gFlushingThread = nsnull;
+  }
+
+  if (gMonitor) {
+    delete gMonitor;
+    gMonitor = nsnull;
+  }
+
+  if (gEventFilter) {
+    delete gEventFilter;
+    gEventFilter = nsnull;
+  }
+#endif
+}
+
+// static 
+void Mark(PRUint32 aType, void * aItem, const char * aText, const char * aText2)
+{
+#ifdef MOZ_VISUAL_EVENT_TRACER
+  if (!gInitialized)
+    return;
+
+  if (aType == eNone)
+    return;
+
+  if (!CheckEventFilters(aType, aItem, aText)) // Events use just aText
+    return;
+
+  RecordBatch * threadLogPrivate = static_cast<RecordBatch *>(
+      PR_GetThreadPrivate(gThreadPrivateIndex));
+  if (!threadLogPrivate) {
+    // Deletion is made by the flushing thread
+    threadLogPrivate = new RecordBatch();
+    PR_SetThreadPrivate(gThreadPrivateIndex, threadLogPrivate);
+  }
+
+  Record * record = threadLogPrivate->mNextRecord;
+  record->mType = aType;
+  record->mTime = (mozilla::TimeStamp::Now() - gProfilerStart).ToMilliseconds();
+  record->mItem = aItem;
+  record->mText = PL_strdup(aText);
+  record->mText2 = aText2 ? PL_strdup(aText2) : nsnull;
+
+  ++threadLogPrivate->mNextRecord;
+  if (threadLogPrivate->mNextRecord == threadLogPrivate->mRecordsTail) {
+    // This calls RecordBatch::FlushBatch(threadLogPrivate)
+    PR_SetThreadPrivate(gThreadPrivateIndex, nsnull);
+  }
+#endif
+}
+
+} // eventtracer
+} // mozilla
new file mode 100644
--- /dev/null
+++ b/xpcom/base/VisualEventTracer.h
@@ -0,0 +1,240 @@
+/* ***** 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 code.
+ *
+ * The Initial Developer of the Original Code is
+ * Mozilla Foundation.
+ * Portions created by the Initial Developer are Copyright (C) 2012
+ * the Initial Developer. All Rights Reserved.
+ *
+ * Contributor(s):
+ *   Honza Bambas <honzab.moz@firemni.cz>
+ *
+ * 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 ***** */
+
+/* Visual event tracer, creates a log of events on each thread for visualization */
+
+/**
+ * The event tracer code is by default disabled in both build and run time.
+ *
+ * To enable this code at build time, add --enable-visual-profiling to your 
+ * configure options.
+ *
+ * To enable this code at run time, export MOZ_PROFILING_FILE env var with 
+ * a path to the file to write the log to.  This is all you need to produce 
+ * the log of all events instrumentation in the mozilla code.
+ * Check MOZ_EVENT_TRACER_* macros bellow to add your own.
+ *
+ * To let the event tracer log only some events to save disk space, export 
+ * MOZ_PROFILING_EVENTS with comma separated list of event names you want 
+ * to record in the log.
+ */
+
+#include "prlock.h"
+#include "nscore.h"
+#include "mozilla/GuardObjects.h"
+
+#ifdef MOZ_VISUAL_EVENT_TRACER
+
+// Bind an object instance, usually |this|, to a name, usually URL or 
+// host name, the instance deals with for its lifetime.  The name string 
+// is duplicated.
+// IMPORTANT: it is up to the caller to pass the correct static_cast
+// of the |instance| pointer to all these macros ; otherwise the linking
+// of events and objects will not work!
+// The name will show in details of the events on the timeline and also
+// will allow events filtering by host names, URLs etc.
+#define MOZ_EVENT_TRACER_NAME_OBJECT(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eName, instance, name)
+
+// The same as MOZ_EVENT_TRACER_NAME_OBJECT, just simplifies building
+// names when it consists of two parts
+#define MOZ_EVENT_TRACER_COMPOUND_NAME(instance, name, name2) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eName, instance, name, name2)
+
+
+// Call the followings with the same |instance| reference as you have 
+// previously called MOZ_EVENT_TRACER_NAME_OBJECT.
+// Let |name| be the name of the event happening, like "resolving", 
+// "connecting", "loading" etc.
+
+// This will crate a single-point-in-time event marked with an arrow 
+// on the timeline, this is a way to indicate an event without a duration.
+#define MOZ_EVENT_TRACER_MARK(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eShot, instance, name)
+
+// Following macros are used to log events with duration.
+// There always has to be complete WAIT,EXEC,DONE or EXEC,DONE 
+// uninterrupted and non-interferring tuple(s) for an event to be correctly 
+// shown on the timeline.  Each can be called on any thread, the event tape is
+// finally displayed on the thread where it has been EXECuted.
+
+// Example of 3 phases usage for "HTTP request channel":
+// WAIT: we've just created the channel and called AsyncOpen on it
+// EXEC: we've just got first call to OnDataAvailable, so we are actually
+//       receiving the content after some time like connection establising,
+//       opening a cache entry, sending the GET request...
+// DONE: we've just got OnStopRequest call that indicates the content
+//       has been completely delivered and the request is now finished
+
+// Indicate an event pending start, on the timeline this will 
+// start the event's interval tape with a pale color, the time will
+// show in details.  Usually used when an event is being posted or
+// we wait for a lock acquisition.
+// WAITING is not mandatory, some events don't have a pending phase.
+#define MOZ_EVENT_TRACER_WAIT(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eWait, instance, name)
+
+// Indicate start of an event actual execution, on the timeline this will 
+// change the event's tape to a deeper color, the time will show in details.
+#define MOZ_EVENT_TRACER_EXEC(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eExec, instance, name)
+
+// Indicate the end of an event execution (the event has been done),
+// on the timeline this will end the event's tape and show the time in
+// event details.
+// NOTE: when the event duration is extremely short, like 1ms, it will convert
+// to an event w/o a duration - the same as MOZ_EVENT_TRACER_MARK would be used.
+#define MOZ_EVENT_TRACER_DONE(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eDone, instance, name)
+
+// The same meaning as the above macros, just for concurent events.
+// Concurent event means it can happen for the same instance on more
+// then just a single thread, e.g. a service method call, a global lock 
+// acquisition, enter and release.
+#define MOZ_EVENT_TRACER_WAIT_THREADSAFE(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eWait | mozilla::eventtracer::eThreadConcurrent, instance, name)
+#define MOZ_EVENT_TRACER_EXEC_THREADSAFE(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eExec | mozilla::eventtracer::eThreadConcurrent, instance, name)
+#define MOZ_EVENT_TRACER_DONE_THREASAFE(instance, name) \
+  mozilla::eventtracer::Mark(mozilla::eventtracer::eDone | mozilla::eventtracer::eThreadConcurrent, instance, name)
+
+#else 
+
+// MOZ_VISUAL_EVENT_TRACER disabled
+
+#define MOZ_EVENT_TRACER_NAME_OBJECT(instance, name) (void)0
+#define MOZ_EVENT_TRACER_COMPOUND_NAME(instance, name, name2) (void)0
+#define MOZ_EVENT_TRACER_MARK(instance, name) (void)0
+#define MOZ_EVENT_TRACER_WAIT(instance, name) (void)0
+#define MOZ_EVENT_TRACER_EXEC(instance, name) (void)0
+#define MOZ_EVENT_TRACER_DONE(instance, name) (void)0
+#define MOZ_EVENT_TRACER_WAIT_THREADSAFE(instance, name) (void)0
+#define MOZ_EVENT_TRACER_EXEC_THREADSAFE(instance, name) (void)0
+#define MOZ_EVENT_TRACER_DONE_THREASAFE(instance, name) (void)0
+
+#endif
+
+
+namespace mozilla { namespace eventtracer {
+
+// Initialize the event tracer engine, called automatically on XPCOM startup.
+void Init();
+
+// Shuts the event tracer engine down and closes the log file, called 
+// automatically during XPCOM shutdown.
+void Shutdown();
+
+enum MarkType {
+  eNone, // No operation, ignored
+  eName, // This is used to bind an object instance with a name
+
+  eShot, // An event with no duration
+  eWait, // Start of waiting for execution (lock acquire, post...)
+  eExec, // Start of the execution it self
+  eDone, // End of the execution
+  eLast, // Sentinel
+
+  // Flags
+
+  // The same object can execute the same event on several threads concurently
+  eThreadConcurrent = 0x10000
+};
+
+// Records an event on the calling thread. 
+// @param aType 
+//    One of MarkType fields, can be bitwise or'ed with the flags.
+// @param aItem
+//    Reference to the object we want to bind a name to or the event is
+//    happening on.  Can be actually anything, but valid poitners should
+//    be used.
+// @param aText
+//    Text of the name (for eName) or event's name for others.  The string
+//    is duplicated.
+// @param aText2
+//    Optional second part of the instnace name, or event name.
+//    Event filtering does apply only to the first part (aText).
+void Mark(PRUint32 aType, void * aItem, 
+          const char * aText, const char * aText2 = 0);
+
+
+// Helper guard object.  Use to mark an event in the constructor and a different
+// event in the destructor.
+//
+// Example:
+// int class::func()
+// {
+//    AutoEventTracer tracer(this, eventtracer::eExec, eventtracer::eDone, "func");
+//
+//    do_something_taking_a_long_time();
+// }
+class NS_STACK_CLASS AutoEventTracer
+{
+public:
+  AutoEventTracer(void * aInstance, 
+               PRUint32 aTypeOn, // MarkType marked in constructor
+               PRUint32 aTypeOff, // MarkType marked in destructor
+               const char * aName, 
+               const char * aName2 = 0 
+               MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
+    : mInstance(aInstance)
+    , mTypeOn(aTypeOn)
+    , mTypeOff(aTypeOff)
+    , mName(aName)
+    , mName2(aName2)
+  {
+    MOZ_GUARD_OBJECT_NOTIFIER_INIT;
+
+    ::mozilla::eventtracer::Mark(mTypeOn, mInstance, mName, mName2);
+  }
+
+  ~AutoEventTracer()
+  {
+    ::mozilla::eventtracer::Mark(mTypeOff, mInstance, mName, mName2);
+  }
+
+private:
+  void * mInstance;
+  const char * mName;
+  const char * mName2;
+  PRUint32 mTypeOn;
+  PRUint32 mTypeOff;
+
+  MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
+};
+
+} // eventtracer 
+} // mozilla
--- a/xpcom/build/nsXPComInit.cpp
+++ b/xpcom/build/nsXPComInit.cpp
@@ -113,16 +113,18 @@ extern nsresult nsStringInputStreamConst
 #include "base/command_line.h"
 #include "base/message_loop.h"
 
 #include "mozilla/ipc/BrowserProcessSubThread.h"
 #include "mozilla/MapsMemoryReporter.h"
 #include "mozilla/AvailableMemoryTracker.h"
 #include "mozilla/ClearOnShutdown.h"
 
+#include "mozilla/VisualEventTracer.h"
+
 using base::AtExitManager;
 using mozilla::ipc::BrowserProcessSubThread;
 
 namespace {
 
 static AtExitManager* sExitManager;
 static MessageLoop* sMessageLoop;
 static bool sCommandLineWasInitialized;
@@ -502,16 +504,18 @@ NS_InitXPCOM2(nsIServiceManager* *result
 #endif
 
     mozilla::MapsMemoryReporter::Init();
 
     mozilla::HangMonitor::Startup();
 
     mozilla::Telemetry::Init();
 
+    mozilla::eventtracer::Init();
+
     return NS_OK;
 }
 
 
 //
 // NS_ShutdownXPCOM()
 //
 // The shutdown sequence for xpcom would be
@@ -714,14 +718,16 @@ ShutdownXPCOM(nsIServiceManager* servMgr
         delete sExitManager;
         sExitManager = nsnull;
     }
 
     Omnijar::CleanUp();
 
     HangMonitor::Shutdown();
 
+    eventtracer::Shutdown();
+
     NS_LogTerm();
 
     return NS_OK;
 }
 
 } // namespace mozilla