Bug 935482: New IOInterposer observer for recording main thread I/O to file; r=froydnj
authorAaron Klotz <aklotz@mozilla.com>
Sat, 19 Apr 2014 14:28:02 -0600
changeset 197857 83c8cecf82977f58aa38dbcf0764d4b208d31989
parent 197856 443dcdf8eed26aa7a2134d970c003d2bd7b85903
child 197858 53a6c96cea62c46160ce9ea80e0d9188fe5ed2df
push id3624
push userasasaki@mozilla.com
push dateMon, 09 Jun 2014 21:49:01 +0000
treeherdermozilla-beta@b1a5da15899a [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersfroydnj
bugs935482
milestone31.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 935482: New IOInterposer observer for recording main thread I/O to file; r=froydnj
toolkit/components/startup/nsAppStartup.cpp
toolkit/components/telemetry/Telemetry.cpp
tools/profiler/ProfilerIOInterposeObserver.cpp
xpcom/build/IOInterposer.cpp
xpcom/build/IOInterposer.h
xpcom/build/IOInterposerPrivate.h
xpcom/build/MainThreadIOLogger.cpp
xpcom/build/MainThreadIOLogger.h
xpcom/build/moz.build
--- a/toolkit/components/startup/nsAppStartup.cpp
+++ b/toolkit/components/startup/nsAppStartup.cpp
@@ -38,16 +38,17 @@
 #include "prenv.h"
 #include "nsAppDirectoryServiceDefs.h"
 
 #if defined(XP_WIN)
 // Prevent collisions with nsAppStartup::GetStartupInfo()
 #undef GetStartupInfo
 #endif
 
+#include "mozilla/IOInterposer.h"
 #include "mozilla/Telemetry.h"
 #include "mozilla/StartupTimeline.h"
 
 static NS_DEFINE_CID(kAppShellCID, NS_APPSHELL_CID);
 
 #define kPrefLastSuccess "toolkit.startup.last_success"
 #define kPrefMaxResumedCrashes "toolkit.startup.max_resumed_crashes"
 #define kPrefRecentCrashes "toolkit.startup.recent_crashes"
@@ -691,30 +692,30 @@ nsAppStartup::Observe(nsISupports *aSubj
       ExitLastWindowClosingSurvivalArea();
     }
   } else if (!strcmp(aTopic, "xul-window-registered")) {
     EnterLastWindowClosingSurvivalArea();
   } else if (!strcmp(aTopic, "xul-window-destroyed")) {
     ExitLastWindowClosingSurvivalArea();
   } else if (!strcmp(aTopic, "sessionstore-windows-restored")) {
     StartupTimeline::Record(StartupTimeline::SESSION_RESTORED);
-    Telemetry::LeavingStartupStage();
+    IOInterposer::EnteringNextStage();
 #if defined(XP_WIN)
     if (mSessionWindowRestoredProbe) {
       mSessionWindowRestoredProbe->Trigger();
     }
   } else if (!strcmp(aTopic, "places-init-complete")) {
     if (mPlacesInitCompleteProbe) {
       mPlacesInitCompleteProbe->Trigger();
     }
 #endif //defined(XP_WIN)
   } else if (!strcmp(aTopic, "sessionstore-init-started")) {
     StartupTimeline::Record(StartupTimeline::SESSION_RESTORE_INIT);
   } else if (!strcmp(aTopic, "xpcom-shutdown")) {
-    Telemetry::EnteringShutdownStage();
+    IOInterposer::EnteringNextStage();
 #if defined(XP_WIN)
     if (mXPCOMShutdownProbe) {
       mXPCOMShutdownProbe->Trigger();
     }
 #endif // defined(XP_WIN)
   } else {
     NS_ERROR("Unexpected observer topic.");
   }
--- a/toolkit/components/telemetry/Telemetry.cpp
+++ b/toolkit/components/telemetry/Telemetry.cpp
@@ -321,34 +321,16 @@ public:
 
   /**
    * Adds a path for inclusion in main thread I/O report.
    * @param aPath Directory path
    * @param aSubstName Name to substitute for aPath for privacy reasons
    */
   void AddPath(const nsAString& aPath, const nsAString& aSubstName);
 
-  enum Stage
-  {
-    STAGE_STARTUP = 0,
-    STAGE_NORMAL,
-    STAGE_SHUTDOWN,
-    NUM_STAGES
-  };
-
-  /**
-   * Sets a new stage in the lifecycle of this process.
-   * @param aNewStage One of the STAGE_* enum values.
-   */
-  inline void SetStage(Stage aNewStage)
-  {
-    MOZ_ASSERT(aNewStage != NUM_STAGES);
-    mCurStage = aNewStage;
-  }
-
   /**
    * Get size of hash table with file stats
    */
   size_t SizeOfIncludingThis(mozilla::MallocSizeOf aMallocSizeOf) const {
     return aMallocSizeOf(this) + SizeOfExcludingThis(aMallocSizeOf);
   }
 
   size_t SizeOfExcludingThis(mozilla::MallocSizeOf aMallocSizeOf) const {
@@ -359,16 +341,37 @@ public:
     uint32_t safeDirsLen = mSafeDirs.Length();
     for (uint32_t i = 0; i < safeDirsLen; ++i) {
       size += mSafeDirs[i].SizeOfExcludingThis(aMallocSizeOf);
     }
     return size;
   }
 
 private:
+  enum Stage
+  {
+    STAGE_STARTUP = 0,
+    STAGE_NORMAL,
+    STAGE_SHUTDOWN,
+    NUM_STAGES
+  };
+  static inline Stage NextStage(Stage aStage)
+  {
+    switch (aStage) {
+      case STAGE_STARTUP:
+        return STAGE_NORMAL;
+      case STAGE_NORMAL:
+        return STAGE_SHUTDOWN;
+      case STAGE_SHUTDOWN:
+        return STAGE_SHUTDOWN;
+      default:
+        return NUM_STAGES;
+    }
+  }
+
   struct FileStatsByStage
   {
     FileStats mStats[NUM_STAGES];
   };
   typedef nsBaseHashtableET<nsStringHashKey, FileStatsByStage> FileIOEntryType;
 
   // Statistics for each filename
   AutoHashtable<FileIOEntryType> mFileStats;
@@ -410,16 +413,22 @@ void TelemetryIOInterposeObserver::AddPa
  
 void TelemetryIOInterposeObserver::Observe(Observation& aOb)
 {
   // We only report main-thread I/O
   if (!IsMainThread()) {
     return;
   }
 
+  if (aOb.ObservedOperation() == OpNextStage) {
+    mCurStage = NextStage(mCurStage);
+    MOZ_ASSERT(mCurStage < NUM_STAGES);
+    return;
+  }
+
   // Get the filename
   const char16_t* filename = aOb.Filename();
  
   // Discard observations without filename
   if (!filename) {
     return;
   }
 
@@ -530,17 +539,18 @@ bool TelemetryIOInterposeObserver::Refle
 StaticAutoPtr<TelemetryIOInterposeObserver> sTelemetryIOObserver;
 
 void
 ClearIOReporting()
 {
   if (!sTelemetryIOObserver) {
     return;
   }
-  IOInterposer::Unregister(IOInterposeObserver::OpAll, sTelemetryIOObserver);
+  IOInterposer::Unregister(IOInterposeObserver::OpAllWithStaging,
+                           sTelemetryIOObserver);
   sTelemetryIOObserver = nullptr;
 }
 
 class TelemetryImpl MOZ_FINAL
   : public nsITelemetry
   , public nsIMemoryReporter
 {
   NS_DECL_THREADSAFE_ISUPPORTS
@@ -2988,17 +2998,18 @@ void
 InitIOReporting(nsIFile* aXreDir)
 {
   // Never initialize twice
   if (sTelemetryIOObserver) {
     return;
   }
 
   sTelemetryIOObserver = new TelemetryIOInterposeObserver(aXreDir);
-  IOInterposer::Register(IOInterposeObserver::OpAll, sTelemetryIOObserver);
+  IOInterposer::Register(IOInterposeObserver::OpAllWithStaging,
+                         sTelemetryIOObserver);
 }
 
 void
 SetProfileDir(nsIFile* aProfD)
 {
   if (!sTelemetryIOObserver || !aProfD) {
     return;
   }
@@ -3006,34 +3017,16 @@ SetProfileDir(nsIFile* aProfD)
   nsresult rv = aProfD->GetPath(profDirPath);
   if (NS_FAILED(rv)) {
     return;
   }
   sTelemetryIOObserver->AddPath(profDirPath, NS_LITERAL_STRING("{profile}"));
 }
 
 void
-LeavingStartupStage()
-{
-  if (!sTelemetryIOObserver) {
-    return;
-  }
-  sTelemetryIOObserver->SetStage(TelemetryIOInterposeObserver::STAGE_NORMAL);
-}
-
-void
-EnteringShutdownStage()
-{
-  if (!sTelemetryIOObserver) {
-    return;
-  }
-  sTelemetryIOObserver->SetStage(TelemetryIOInterposeObserver::STAGE_SHUTDOWN);
-}
-
-void
 TimeHistogram::Add(PRIntervalTime aTime)
 {
   uint32_t timeMs = PR_IntervalToMilliseconds(aTime);
   size_t index = mozilla::FloorLog2(timeMs);
   operator[](index)++;
 }
 
 uint32_t
--- a/tools/profiler/ProfilerIOInterposeObserver.cpp
+++ b/tools/profiler/ProfilerIOInterposeObserver.cpp
@@ -9,46 +9,22 @@
 using namespace mozilla;
 
 void ProfilerIOInterposeObserver::Observe(Observation& aObservation)
 {
   if (!IsMainThread()) {
     return;
   }
 
-  const char* str = nullptr;
-
-  switch (aObservation.ObservedOperation()) {
-    case IOInterposeObserver::OpCreateOrOpen:
-      str = "create/open";
-      break;
-    case IOInterposeObserver::OpRead:
-      str = "read";
-      break;
-    case IOInterposeObserver::OpWrite:
-      str = "write";
-      break;
-    case IOInterposeObserver::OpFSync:
-      str = "fsync";
-      break;
-    case IOInterposeObserver::OpStat:
-      str = "stat";
-      break;
-    case IOInterposeObserver::OpClose:
-      str = "close";
-      break;
-    default:
-      return;
-  }
   ProfilerBacktrace* stack = profiler_get_backtrace();
 
   nsCString filename;
   if (aObservation.Filename()) {
     filename = NS_ConvertUTF16toUTF8(aObservation.Filename());
   }
 
   IOMarkerPayload* markerPayload = new IOMarkerPayload(aObservation.Reference(),
                                                        filename.get(),
                                                        aObservation.Start(),
                                                        aObservation.End(),
                                                        stack);
-  PROFILER_MARKER_PAYLOAD(str, markerPayload);
+  PROFILER_MARKER_PAYLOAD(aObservation.ObservedOperationString(), markerPayload);
 }
--- a/xpcom/build/IOInterposer.cpp
+++ b/xpcom/build/IOInterposer.cpp
@@ -2,16 +2,18 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include <algorithm>
 #include <vector>
 
 #include "IOInterposer.h"
 
+#include "IOInterposerPrivate.h"
+#include "MainThreadIOLogger.h"
 #include "mozilla/Atomics.h"
 #include "mozilla/Mutex.h"
 #if defined(MOZILLA_INTERNAL_API)
 // We need to undefine MOZILLA_INTERNAL_API for RefPtr.h because IOInterposer
 // does not clean up its data before shutdown.
 #undef MOZILLA_INTERNAL_API
 #include "mozilla/RefPtr.h"
 #define MOZILLA_INTERNAL_API
@@ -42,59 +44,43 @@ template<class T>
 void VectorRemove(std::vector<T>& vector, const T& element)
 {
   typename std::vector<T>::iterator newEnd = std::remove(vector.begin(),
                                                          vector.end(), element);
   vector.erase(newEnd, vector.end());
 }
 
 /** Lists of Observers */
-struct ObserverLists : public AtomicRefCounted<ObserverLists>
+struct ObserverLists : public mozilla::AtomicRefCounted<ObserverLists>
 {
   ObserverLists()
   {
   }
 
   ObserverLists(ObserverLists const & aOther)
     : mCreateObservers(aOther.mCreateObservers)
     , mReadObservers(aOther.mReadObservers)
     , mWriteObservers(aOther.mWriteObservers)
     , mFSyncObservers(aOther.mFSyncObservers)
     , mStatObservers(aOther.mStatObservers)
     , mCloseObservers(aOther.mCloseObservers)
+    , mStageObservers(aOther.mStageObservers)
   {
   }
-  // Lists of observers for read, write and fsync events respectively
+  // Lists of observers for I/O events.
   // These are implemented as vectors since they are allowed to survive gecko,
   // without reporting leaks. This is necessary for the IOInterposer to be used
   // for late-write checks.
   std::vector<IOInterposeObserver*>  mCreateObservers;
   std::vector<IOInterposeObserver*>  mReadObservers;
   std::vector<IOInterposeObserver*>  mWriteObservers;
   std::vector<IOInterposeObserver*>  mFSyncObservers;
   std::vector<IOInterposeObserver*>  mStatObservers;
   std::vector<IOInterposeObserver*>  mCloseObservers;
-};
-
-/**
- * A quick and dirty RAII class to automatically lock a PRLock
- */
-class AutoPRLock
-{
-  PRLock* mLock;
-public:
-  AutoPRLock(PRLock* aLock)
-   : mLock(aLock)
-  {
-    PR_Lock(aLock);
-  }
-  ~AutoPRLock()
-  {
-    PR_Unlock(mLock);
-  }
+  std::vector<IOInterposeObserver*>  mStageObservers;
 };
 
 class PerThreadData
 {
 public:
   PerThreadData(bool aIsMainThread = false)
     : mIsMainThread(aIsMainThread)
     , mIsHandlingObservation(false)
@@ -139,16 +125,21 @@ public:
           observers = &mObserverLists->mStatObservers;
         }
         break;
       case IOInterposeObserver::OpClose:
         {
           observers = &mObserverLists->mCloseObservers;
         }
         break;
+      case IOInterposeObserver::OpNextStage:
+        {
+          observers = &mObserverLists->mStageObservers;
+        }
+        break;
       default:
         {
           // Invalid IO operation, see documentation comment for
           // IOInterposer::Report()
           MOZ_ASSERT(false);
           // Just ignore it in non-debug builds.
           return;
         }
@@ -189,38 +180,35 @@ private:
   uint32_t              mCurrentGeneration;
   RefPtr<ObserverLists> mObserverLists;
 };
 
 class MasterList
 {
 public:
   MasterList()
-    : mLock(PR_NewLock())
-    , mObservedOperations(IOInterposeObserver::OpNone)
+    : mObservedOperations(IOInterposeObserver::OpNone)
     , mIsEnabled(true)
   {
   }
 
   ~MasterList()
   {
-    PR_DestroyLock(mLock);
-    mLock = nullptr;
   }
 
   inline void
   Disable()
   {
     mIsEnabled = false;
   }
 
   void
   Register(IOInterposeObserver::Operation aOp, IOInterposeObserver* aObserver)
   {
-    AutoPRLock lock(mLock);
+    IOInterposer::AutoLock lock(mLock);
 
     ObserverLists* newLists = nullptr;
     if (mObserverLists) {
       newLists = new ObserverLists(*mObserverLists);
     } else {
       newLists = new ObserverLists();
     }
     // You can register to observe multiple types of observations
@@ -244,27 +232,31 @@ public:
     if (aOp & IOInterposeObserver::OpStat &&
         !VectorContains(newLists->mStatObservers, aObserver)) {
       newLists->mStatObservers.push_back(aObserver);
     }
     if (aOp & IOInterposeObserver::OpClose &&
         !VectorContains(newLists->mCloseObservers, aObserver)) {
       newLists->mCloseObservers.push_back(aObserver);
     }
+    if (aOp & IOInterposeObserver::OpNextStage &&
+        !VectorContains(newLists->mStageObservers, aObserver)) {
+      newLists->mStageObservers.push_back(aObserver);
+    }
     mObserverLists = newLists;
     mObservedOperations = (IOInterposeObserver::Operation)
                             (mObservedOperations | aOp);
 
     mCurrentGeneration++;
   }
 
   void
   Unregister(IOInterposeObserver::Operation aOp, IOInterposeObserver* aObserver)
   {
-    AutoPRLock lock(mLock);
+    IOInterposer::AutoLock lock(mLock);
 
     ObserverLists* newLists = nullptr;
     if (mObserverLists) {
       newLists = new ObserverLists(*mObserverLists);
     } else {
       newLists = new ObserverLists();
     }
 
@@ -306,29 +298,36 @@ public:
     }
     if (aOp & IOInterposeObserver::OpClose) {
       VectorRemove(newLists->mCloseObservers, aObserver);
       if (newLists->mCloseObservers.empty()) {
         mObservedOperations = (IOInterposeObserver::Operation)
                          (mObservedOperations & ~IOInterposeObserver::OpClose);
       }
     }
+    if (aOp & IOInterposeObserver::OpNextStage) {
+      VectorRemove(newLists->mStageObservers, aObserver);
+      if (newLists->mStageObservers.empty()) {
+        mObservedOperations = (IOInterposeObserver::Operation)
+                         (mObservedOperations & ~IOInterposeObserver::OpNextStage);
+      }
+    }
     mObserverLists = newLists;
     mCurrentGeneration++;
   }
  
   void
   Update(PerThreadData &aPtd)
   {
     if (mCurrentGeneration == aPtd.GetCurrentGeneration()) {
       return;
     }
     // If the generation counts don't match then we need to update the current
     // thread's observer list with the new master list.
-    AutoPRLock lock(mLock);
+    IOInterposer::AutoLock lock(mLock);
     aPtd.SetObserverLists(mCurrentGeneration, mObserverLists);
   }
 
   inline bool
   IsObservedOperation(IOInterposeObserver::Operation aOp)
   {
     // The quick reader may observe that no locks are being employed here,
     // hence the result of the operations is truly undefined. However, most
@@ -340,25 +339,37 @@ public:
 
 private:
   RefPtr<ObserverLists>             mObserverLists;
   // Note, we cannot use mozilla::Mutex here as the ObserverLists may be leaked
   // (We want to monitor IO during shutdown). Furthermore, as we may have to
   // unregister observers during shutdown an OffTheBooksMutex is not an option
   // either, as its base calls into sDeadlockDetector which may be nullptr
   // during shutdown.
-  PRLock*                           mLock;
+  IOInterposer::Mutex               mLock;
   // Flags tracking which operations are being observed
   IOInterposeObserver::Operation    mObservedOperations;
   // Used for quickly disabling everything by IOInterposer::Disable()
   Atomic<bool>                      mIsEnabled;
   // Used to inform threads that the master observer list has changed
   Atomic<uint32_t>                  mCurrentGeneration;
 };
 
+// Special observation used by IOInterposer::EnteringNextStage()
+class NextStageObservation : public IOInterposeObserver::Observation
+{
+public:
+  NextStageObservation()
+    : IOInterposeObserver::Observation(IOInterposeObserver::OpNextStage,
+                                       "IOInterposer", false)
+  {
+    mStart = TimeStamp::Now();
+  }
+};
+
 // List of observers registered
 static StaticAutoPtr<MasterList> sMasterList;
 static ThreadLocal<PerThreadData*> sThreadLocalData;
 } // anonymous namespace
 
 IOInterposeObserver::Observation::Observation(Operation aOperation,
                                               const char* aReference,
                                               bool aShouldReport)
@@ -379,26 +390,49 @@ IOInterposeObserver::Observation::Observ
   : mOperation(aOperation)
   , mStart(aStart)
   , mEnd(aEnd)
   , mReference(aReference)
   , mShouldReport(false)
 {
 }
 
+const char*
+IOInterposeObserver::Observation::ObservedOperationString() const
+{
+  switch(mOperation) {
+    case OpCreateOrOpen:
+      return "create/open";
+    case OpRead:
+      return "read";
+    case OpWrite:
+      return "write";
+    case OpFSync:
+      return "fsync";
+    case OpStat:
+      return "stat";
+    case OpClose:
+      return "close";
+    case OpNextStage:
+      return "NextStage";
+    default:
+      return "unknown";
+  }
+}
+
 void
 IOInterposeObserver::Observation::Report()
 {
   if (mShouldReport) {
     mEnd = TimeStamp::Now();
     IOInterposer::Report(*this);
   }
 }
 
-/* static */ bool
+bool
 IOInterposer::Init()
 {
   // Don't initialize twice...
   if (sMasterList) {
     return true;
   }
   if (!sThreadLocalData.init()) {
     return false;
@@ -407,55 +441,57 @@ IOInterposer::Init()
   bool isMainThread = XRE_GetWindowsEnvironment() !=
                         WindowsEnvironmentType_Metro;
 #else
   bool isMainThread = true;
 #endif
   RegisterCurrentThread(isMainThread);
   sMasterList = new MasterList();
 
+  MainThreadIOLogger::Init();
+
   // Now we initialize the various interposers depending on platform
   InitPoisonIOInterposer();
   // We don't hook NSPR on Windows because PoisonIOInterposer captures a
   // superset of the former's events.
 #if !defined(XP_WIN)
   InitNSPRIOInterposing();
 #endif
   return true;
 }
 
-/* static */ bool
+bool
 IOInterposeObserver::IsMainThread()
 {
   if (!sThreadLocalData.initialized()) {
     return false;
   }
   PerThreadData *ptd = sThreadLocalData.get();
   if (!ptd) {
     return false;
   }
   return ptd->IsMainThread();
 }
 
-/* static */ void
+void
 IOInterposer::Clear()
 {
   sMasterList = nullptr;
 }
 
-/* static */ void
+void
 IOInterposer::Disable()
 {
   if (!sMasterList) {
     return;
   }
   sMasterList->Disable();
 }
 
-/* static */ void
+void
 IOInterposer::Report(IOInterposeObserver::Observation& aObservation)
 {
   MOZ_ASSERT(sMasterList);
   if (!sMasterList) {
     return;
   }
 
   PerThreadData* ptd = sThreadLocalData.get();
@@ -470,60 +506,70 @@ IOInterposer::Report(IOInterposeObserver
   // Don't try to report if there's nobody listening.
   if (!IOInterposer::IsObservedOperation(aObservation.ObservedOperation())) {
     return;
   }
 
   ptd->CallObservers(aObservation);
 }
 
-/* static */ bool
+bool
 IOInterposer::IsObservedOperation(IOInterposeObserver::Operation aOp)
 {
   return sMasterList && sMasterList->IsObservedOperation(aOp);
 }
 
-/* static */ void
+void
 IOInterposer::Register(IOInterposeObserver::Operation aOp,
                        IOInterposeObserver* aObserver)
 {
   MOZ_ASSERT(aObserver);
   if (!sMasterList || !aObserver) {
     return;
   }
 
   sMasterList->Register(aOp, aObserver);
 }
 
-/* static */ void
+void
 IOInterposer::Unregister(IOInterposeObserver::Operation aOp,
                          IOInterposeObserver* aObserver)
 {
   if (!sMasterList) {
     return;
   }
 
   sMasterList->Unregister(aOp, aObserver);
 }
 
-/* static */ void
+void
 IOInterposer::RegisterCurrentThread(bool aIsMainThread)
 {
   if (!sThreadLocalData.initialized()) {
     return;
   }
   MOZ_ASSERT(!sThreadLocalData.get());
   PerThreadData* curThreadData = new PerThreadData(aIsMainThread);
   sThreadLocalData.set(curThreadData);
 }
 
-/* static */ void
+void
 IOInterposer::UnregisterCurrentThread()
 {
   if (!sThreadLocalData.initialized()) {
     return;
   }
   PerThreadData* curThreadData = sThreadLocalData.get();
   MOZ_ASSERT(curThreadData);
   sThreadLocalData.set(nullptr);
   delete curThreadData;
 }
 
+void
+IOInterposer::EnteringNextStage()
+{
+  if (!sMasterList) {
+    return;
+  }
+  NextStageObservation observation;
+  Report(observation);
+}
+
--- a/xpcom/build/IOInterposer.h
+++ b/xpcom/build/IOInterposer.h
@@ -22,18 +22,20 @@ public:
   {
     OpNone = 0,
     OpCreateOrOpen = (1 << 0),
     OpRead = (1 << 1),
     OpWrite = (1 << 2),
     OpFSync = (1 << 3),
     OpStat = (1 << 4),
     OpClose = (1 << 5),
+    OpNextStage = (1 << 6), // Meta - used when leaving startup, entering shutdown
     OpWriteFSync = (OpWrite | OpFSync),
-    OpAll = (OpCreateOrOpen | OpRead | OpWrite | OpFSync | OpStat | OpClose)
+    OpAll = (OpCreateOrOpen | OpRead | OpWrite | OpFSync | OpStat | OpClose),
+    OpAllWithStaging = (OpAll | OpNextStage)
   };
 
   /** A representation of an I/O observation  */
   class Observation
   {
   protected:
     /**
      * This constructor is for use by subclasses that are intended to take
@@ -51,24 +53,29 @@ public:
     /**
      * Since this constructor accepts start and end times, it does *not* take
      * its own timings, nor does it report itself.
      */
     Observation(Operation aOperation, const TimeStamp& aStart,
                 const TimeStamp& aEnd, const char* aReference);
 
     /**
-     * Operation observed, this is either OpRead, OpWrite or OpFSync,
-     * combinations of these flags are only used when registering observers.
+     * Operation observed, this is one of the individual Operation values.
+     * Combinations of these flags are only used when registering observers.
      */
     Operation ObservedOperation() const
     {
       return mOperation;
     }
 
+    /**
+     * Return the observed operation as a human-readable string.
+     */
+    const char* ObservedOperationString() const;
+
     /** Time at which the I/O operation was started */
     TimeStamp Start() const
     {
       return mStart;
     }
 
     /**
      * Time at which the I/O operation ended, for asynchronous methods this is
@@ -142,64 +149,53 @@ protected:
    * We don't use NS_IsMainThread() because we need to be able to determine the
    * main thread outside of XPCOM Initialization. IOInterposer observers should
    * call this function instead.
    */
   static bool IsMainThread();
 };
 
 /**
- * Class offering the public static IOInterposer API.
- *
- * This class is responsible for ensuring that events are routed to the
- * appropriate observers. Methods Init() and Clear() should only be called from
- * the main-thread at startup and shutdown, respectively.
- *
- * Remark: Instances of this class will never be created, you should consider it
- * to be a namespace containing static functions. The class is created to
- * facilitate to a private static instance variable sObservedOperations.
- * As we want to access this from an inline static methods, we have to do this
- * trick.
+ * These functions are responsible for ensuring that events are routed to the
+ * appropriate observers.
  */
-class IOInterposer MOZ_FINAL
+namespace IOInterposer
 {
-  // No instance of class should be created, they'd be empty anyway.
-  IOInterposer();
-public:
-
   /**
    * This function must be called from the main-thread when no other threads are
    * running before any of the other methods on this class may be used.
    *
    * IO reports can however, safely assume that IsObservedOperation() will
-   * return false, until the IOInterposer is initialized.
+   * return false until the IOInterposer is initialized.
    *
    * Remark, it's safe to call this method multiple times, so just call it when
    * you to utilize IO interposing.
+   *
+   * Using the IOInterposerInit class is preferred to calling this directly.
    */
-  static bool Init();
+  bool Init();
 
   /**
    * This function must be called from the main thread, and furthermore
    * it must be called when no other threads are executing. Effectively
    * restricting us to calling it only during shutdown.
    *
    * Callers should take care that no other consumers are subscribed to events,
    * as these events will stop when this function is called.
    *
-   * In practice, we don't use this method, as the IOInterposer is used for
+   * In practice, we don't use this method as the IOInterposer is used for
    * late-write checks.
    */
-  static void Clear();
+  void Clear();
 
   /**
    * This function immediately disables IOInterposer functionality in a fast,
    * thread-safe manner. Primarily for use by the crash reporter.
    */
-  static void Disable();
+  void Disable();
 
   /**
    * Report IO to registered observers.
    * Notice that the reported operation must be either OpRead, OpWrite or
    * OpFSync. You are not allowed to report an observation with OpWriteFSync or
    * OpAll, these are just auxiliary values for use with Register().
    *
    * If the IO call you're reporting does multiple things, write and fsync, you
@@ -211,67 +207,74 @@ public:
    * which is not being observed. Use IsObservedOperation() to check if the
    * operation you are about to report is being observed. This is especially
    * important if you are constructing expensive observations containing
    * filename and full-path.
    *
    * Remark: Init() must be called before any IO is reported. But
    * IsObservedOperation() will return false until Init() is called.
    */
-  static void Report(IOInterposeObserver::Observation& aObservation);
+  void Report(IOInterposeObserver::Observation& aObservation);
 
   /**
    * Return whether or not an operation is observed. Reporters should not
    * report operations that are not being observed by anybody. This mechanism
    * allows us to avoid reporting I/O when no observers are registered.
    */
-  static bool IsObservedOperation(IOInterposeObserver::Operation aOp);
+  bool IsObservedOperation(IOInterposeObserver::Operation aOp);
 
   /**
    * Register IOInterposeObserver, the observer object will receive all
    * observations for the given operation aOp.
    *
    * Remark: Init() must be called before observers are registered.
    */
-  static void Register(IOInterposeObserver::Operation aOp,
-                       IOInterposeObserver* aObserver);
+  void Register(IOInterposeObserver::Operation aOp,
+                IOInterposeObserver* aObserver);
 
   /**
    * Unregister an IOInterposeObserver for a given operation
    * Remark: It is always safe to unregister for all operations, even if yoú
    * didn't register for them all.
    * I.e. IOInterposer::Unregister(IOInterposeObserver::OpAll, aObserver)
    *
    * Remark: Init() must be called before observers are unregistered.
    */
-  static void Unregister(IOInterposeObserver::Operation aOp,
-                         IOInterposeObserver* aObserver);
+  void Unregister(IOInterposeObserver::Operation aOp,
+                  IOInterposeObserver* aObserver);
 
   /**
    * Registers the current thread with the IOInterposer. This must be done to
    * ensure that per-thread data is created in an orderly fashion.
    * We could have written this to initialize that data lazily, however this
    * could have unintended consequences if a thread that is not aware of
    * IOInterposer was implicitly registered: its per-thread data would never
    * be deleted because it would not know to unregister itself.
    *
    * @param aIsMainThread true if IOInterposer should treat the current thread
    *                      as the main thread.
    */
-  static void
+  void
   RegisterCurrentThread(bool aIsMainThread = false);
 
   /**
    * Unregisters the current thread with the IOInterposer. This is important
    * to call when a thread is shutting down because it cleans up data that
    * is stored in a TLS slot.
    */
-  static void
+  void
   UnregisterCurrentThread();
-};
+
+  /**
+   * Called to inform observers that the process has transitioned out of the
+   * startup stage or into the shutdown stage. Main thread only.
+   */
+  void
+  EnteringNextStage();
+} // namespace IOInterposer
 
 class IOInterposerInit
 {
 public:
   IOInterposerInit()
   {
 #if defined(MOZ_ENABLE_PROFILER_SPS)
     IOInterposer::Init();
new file mode 100644
--- /dev/null
+++ b/xpcom/build/IOInterposerPrivate.h
@@ -0,0 +1,167 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
+/* vim: set ts=8 sts=2 et sw=2 tw=80: */
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+#ifndef xpcom_build_IOInterposerPrivate_h
+#define xpcom_build_IOInterposerPrivate_h
+
+/* This header file contains declarations for helper classes that are
+   to be used exclusively by IOInterposer and its observers. This header
+   file is not to be used by anything else and MUST NOT be exported! */
+
+#include <prcvar.h>
+#include <prlock.h>
+
+namespace mozilla {
+namespace IOInterposer {
+
+/**
+ * The following classes are simple wrappers for PRLock and PRCondVar.
+ * IOInterposer and friends use these instead of Mozilla::Mutex et al because
+ * of the fact that IOInterposer is permitted to run until the process
+ * terminates; we can't use anything that plugs into leak checkers or deadlock
+ * detectors because IOInterposer will outlive those and generate false
+ * positives.
+ */
+
+class Monitor
+{
+public:
+  Monitor()
+    : mLock(PR_NewLock())
+    , mCondVar(PR_NewCondVar(mLock))
+  {
+  }
+
+  ~Monitor()
+  {
+    PR_DestroyCondVar(mCondVar);
+    mCondVar = nullptr;
+    PR_DestroyLock(mLock);
+    mLock = nullptr;
+  }
+
+  void Lock()
+  {
+    PR_Lock(mLock);
+  }
+
+  void Unlock()
+  {
+    PR_Unlock(mLock);
+  }
+
+  bool Wait(PRIntervalTime aTimeout = PR_INTERVAL_NO_TIMEOUT)
+  {
+    return PR_WaitCondVar(mCondVar, aTimeout) == PR_SUCCESS;
+  }
+
+  bool Notify()
+  {
+    return PR_NotifyCondVar(mCondVar) == PR_SUCCESS;
+  }
+
+private:
+  PRLock*    mLock;
+  PRCondVar* mCondVar;
+};
+
+class MonitorAutoLock
+{
+public:
+  MonitorAutoLock(Monitor &aMonitor)
+    : mMonitor(aMonitor)
+  {
+    mMonitor.Lock();
+  }
+
+  ~MonitorAutoLock()
+  {
+    mMonitor.Unlock();
+  }
+
+  bool Wait(PRIntervalTime aTimeout = PR_INTERVAL_NO_TIMEOUT)
+  {
+    return mMonitor.Wait(aTimeout);
+  }
+
+  bool Notify()
+  {
+    return mMonitor.Notify();
+  }
+
+private:
+  Monitor&  mMonitor;
+};
+
+class MonitorAutoUnlock
+{
+public:
+  MonitorAutoUnlock(Monitor &aMonitor)
+    : mMonitor(aMonitor)
+  {
+    mMonitor.Unlock();
+  }
+
+  ~MonitorAutoUnlock()
+  {
+    mMonitor.Lock();
+  }
+
+private:
+  Monitor&  mMonitor;
+};
+
+class Mutex
+{
+public:
+  Mutex()
+    : mPRLock(PR_NewLock())
+  {
+  }
+
+  ~Mutex()
+  {
+    PR_DestroyLock(mPRLock);
+    mPRLock = nullptr;
+  }
+
+  void Lock()
+  {
+    PR_Lock(mPRLock);
+  }
+
+  void Unlock()
+  {
+    PR_Unlock(mPRLock);
+  }
+
+private:
+  PRLock*   mPRLock;
+};
+
+class AutoLock
+{
+public:
+  AutoLock(Mutex& aLock)
+    : mLock(aLock)
+  {
+    mLock.Lock();
+  }
+
+  ~AutoLock()
+  {
+    mLock.Unlock();
+  }
+
+private:
+  Mutex&     mLock;
+};
+
+} // namespace IOInterposer
+} // namespace mozilla
+
+#endif // xpcom_build_IOInterposerPrivate_h
+
new file mode 100644
--- /dev/null
+++ b/xpcom/build/MainThreadIOLogger.cpp
@@ -0,0 +1,221 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
+/* vim: set ts=8 sts=2 et sw=2 tw=80: */
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+#include "MainThreadIOLogger.h"
+
+#include "GeckoProfiler.h"
+#include "IOInterposerPrivate.h"
+#include "mozilla/IOInterposer.h"
+#include "mozilla/StaticPtr.h"
+#include "mozilla/TimeStamp.h"
+
+/**
+ * This code uses NSPR stuff and STL containers because it must be detached
+ * from leak checking code; this observer runs until the process terminates.
+ */
+
+#include <prenv.h>
+#include <prprf.h>
+#include <prthread.h>
+#include <vector>
+
+namespace {
+
+struct ObservationWithStack
+{
+  ObservationWithStack(mozilla::IOInterposeObserver::Observation& aObs,
+                       ProfilerBacktrace *aStack)
+    : mObservation(aObs)
+    , mStack(aStack)
+  {
+    const char16_t* filename = aObs.Filename();
+    if (filename) {
+      mFilename = filename;
+    }
+  }
+ 
+  mozilla::IOInterposeObserver::Observation mObservation;
+  ProfilerBacktrace*                        mStack;
+  nsString                                  mFilename;
+};
+
+} // anonymous namespace
+
+namespace mozilla {
+
+class MainThreadIOLoggerImpl MOZ_FINAL : public IOInterposeObserver
+{
+public:
+  MainThreadIOLoggerImpl();
+  ~MainThreadIOLoggerImpl();
+
+  bool Init();
+
+  void Observe(Observation& aObservation);
+
+private:
+  static void sIOThreadFunc(void* aArg);
+  void IOThreadFunc();
+
+  TimeStamp             mLogStartTime;
+  const char*           mFileName;
+  PRThread*             mIOThread;
+  IOInterposer::Monitor mMonitor;
+  bool                  mShutdownRequired;
+  std::vector<ObservationWithStack> mObservations;
+};
+
+static StaticAutoPtr<MainThreadIOLoggerImpl> sImpl;
+
+MainThreadIOLoggerImpl::MainThreadIOLoggerImpl()
+  : mFileName(nullptr)
+  , mIOThread(nullptr)
+  , mShutdownRequired(false)
+{
+}
+
+MainThreadIOLoggerImpl::~MainThreadIOLoggerImpl()
+{
+  if (!mIOThread) {
+    return;
+  }
+  { // Scope for lock
+    IOInterposer::MonitorAutoLock lock(mMonitor);
+    mShutdownRequired = true;
+    lock.Notify();
+  }
+  PR_JoinThread(mIOThread);
+  mIOThread = nullptr;
+}
+
+bool
+MainThreadIOLoggerImpl::Init()
+{
+  if (mFileName) {
+    // Already initialized
+    return true;
+  }
+  mFileName = PR_GetEnv("MOZ_MAIN_THREAD_IO_LOG");
+  if (!mFileName) {
+    // Can't start
+    return false;
+  }
+  mIOThread = PR_CreateThread(PR_USER_THREAD, &sIOThreadFunc, this,
+                              PR_PRIORITY_LOW, PR_GLOBAL_THREAD,
+                              PR_JOINABLE_THREAD, 0);
+  if (!mIOThread) {
+    return false;
+  }
+  return true;
+}
+
+/* static */ void
+MainThreadIOLoggerImpl::sIOThreadFunc(void* aArg)
+{
+  PR_SetCurrentThreadName("MainThreadIOLogger");
+  MainThreadIOLoggerImpl* obj = static_cast<MainThreadIOLoggerImpl*>(aArg);
+  obj->IOThreadFunc();
+}
+
+void
+MainThreadIOLoggerImpl::IOThreadFunc()
+{
+  PRFileDesc* fd = PR_Open(mFileName, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
+                           PR_IRUSR | PR_IWUSR | PR_IRGRP);
+  if (!fd) {
+    IOInterposer::MonitorAutoLock lock(mMonitor);
+    mShutdownRequired = true;
+    std::vector<ObservationWithStack>().swap(mObservations);
+    return;
+  }
+  mLogStartTime = TimeStamp::Now();
+  { // Scope for lock
+    IOInterposer::MonitorAutoLock lock(mMonitor);
+    while (true) {
+      while (!mShutdownRequired && mObservations.empty()) {
+        lock.Wait();
+      }
+      if (mShutdownRequired) {
+        break;
+      }
+      // Pull events off the shared array onto a local one
+      std::vector<ObservationWithStack> observationsToWrite;
+      observationsToWrite.swap(mObservations);
+ 
+      // Release the lock so that we're not holding anybody up during I/O
+      IOInterposer::MonitorAutoUnlock unlock(mMonitor);
+
+      // Now write the events.
+      for (std::vector<ObservationWithStack>::iterator
+             i = observationsToWrite.begin(), e = observationsToWrite.end();
+           i != e; ++i) {
+        if (i->mObservation.ObservedOperation() == OpNextStage) {
+          PR_fprintf(fd, "%f,NEXT-STAGE\n",
+                     (TimeStamp::Now() - mLogStartTime).ToMilliseconds());
+          continue;
+        }
+        double durationMs = i->mObservation.Duration().ToMilliseconds();
+        nsAutoCString nativeFilename;
+        nativeFilename.AssignLiteral("(not available)");
+        if (!i->mFilename.IsEmpty()) {
+          if (NS_FAILED(NS_CopyUnicodeToNative(i->mFilename, nativeFilename))) {
+            nativeFilename.AssignLiteral("(conversion failed)");
+          }
+        }
+        /**
+         * Format:
+         * Start Timestamp (Milliseconds), Operation, Duration (Milliseconds), Event Source, Filename
+         */
+        if (PR_fprintf(fd, "%f,%s,%f,%s,%s\n",
+                       (i->mObservation.Start() - mLogStartTime).ToMilliseconds(),
+                       i->mObservation.ObservedOperationString(), durationMs,
+                       i->mObservation.Reference(), nativeFilename.get()) > 0) {
+          ProfilerBacktrace* stack = i->mStack;
+          if (stack) {
+            // TODO: Write out the callstack
+            //       (This will be added in a later bug)
+            profiler_free_backtrace(stack);
+          }
+        }
+      }
+    }
+  }
+  PR_Close(fd);
+}
+
+void
+MainThreadIOLoggerImpl::Observe(Observation& aObservation)
+{
+  if (!mFileName || !IsMainThread()) {
+    return;
+  }
+  IOInterposer::MonitorAutoLock lock(mMonitor);
+  if (mShutdownRequired) {
+    // The writer thread isn't running. Don't enqueue any more data.
+    return;
+  }
+  // Passing nullptr as aStack parameter for now
+  mObservations.push_back(ObservationWithStack(aObservation, nullptr));
+  lock.Notify();
+}
+
+namespace MainThreadIOLogger {
+
+bool
+Init()
+{
+  sImpl = new MainThreadIOLoggerImpl();
+  if (!sImpl->Init()) {
+    return false;
+  }
+  IOInterposer::Register(IOInterposeObserver::OpAllWithStaging, sImpl);
+  return true;
+}
+
+} // namespace MainThreadIOLogger
+
+} // namespace mozilla
+
new file mode 100644
--- /dev/null
+++ b/xpcom/build/MainThreadIOLogger.h
@@ -0,0 +1,19 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
+/* vim: set ts=8 sts=2 et sw=2 tw=80: */
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+#ifndef mozilla_MainThreadIOLogger_h
+#define mozilla_MainThreadIOLogger_h
+
+namespace mozilla {
+namespace MainThreadIOLogger {
+
+bool Init();
+
+} // namespace MainThreadIOLogger
+} // namespace mozilla
+
+#endif // mozilla_MainThreadIOLogger_h
+
--- a/xpcom/build/moz.build
+++ b/xpcom/build/moz.build
@@ -45,16 +45,17 @@ include('../glue/objs.mozbuild')
 
 UNIFIED_SOURCES += xpcom_gluens_src_cppsrcs
 UNIFIED_SOURCES += xpcom_glue_src_cppsrcs
 
 UNIFIED_SOURCES += [
     'FrozenFunctions.cpp',
     'IOInterposer.cpp',
     'LateWriteChecks.cpp',
+    'MainThreadIOLogger.cpp',
     'nsXPComInit.cpp',
     'nsXPCOMStrings.cpp',
     'Services.cpp',
 ]
 
 if CONFIG['OS_ARCH'] != 'WINNT':
     SOURCES += [
         'NSPRInterposer.cpp',