Bug 1329929 - Fix memory leaking of TaskTracer. r=cervantes
authorThinker K.F. Li <thinker@codemud.net>
Wed, 22 Feb 2017 00:26:00 -0500
changeset 344588 05fcaf50a7b9969601901a1951b453171bceb0b1
parent 344587 4fff02e2a6a2d1d8f3ea81c7ab3f30374b9e03c9
child 344589 11a711ac2407fb856937c870f8d2a08311be3221
push id31414
push usercbook@mozilla.com
push dateFri, 24 Feb 2017 10:47:41 +0000
treeherdermozilla-central@be661bae6cb9 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerscervantes
bugs1329929
milestone54.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 1329929 - Fix memory leaking of TaskTracer. r=cervantes
tools/profiler/tasktracer/GeckoTaskTracer.cpp
tools/profiler/tasktracer/GeckoTaskTracerImpl.h
tools/profiler/tasktracer/TracedTaskCommon.cpp
--- a/tools/profiler/tasktracer/GeckoTaskTracer.cpp
+++ b/tools/profiler/tasktracer/GeckoTaskTracer.cpp
@@ -52,51 +52,53 @@ namespace tasktracer {
 #include "SourceEventTypeMap.h"
 #undef SOURCE_EVENT_NAME
 
 static MOZ_THREAD_LOCAL(TraceInfo*) sTraceInfoTLS;
 static mozilla::StaticMutex sMutex;
 
 // The generation of TraceInfo. It will be > 0 if the Task Tracer is started and
 // <= 0 if stopped.
-static mozilla::Atomic<bool> sStarted;
+static mozilla::Atomic<bool> sStarted(false);
 static nsTArray<UniquePtr<TraceInfo>>* sTraceInfos = nullptr;
 static PRTime sStartTime;
 
 static const char sJSLabelPrefix[] = "#tt#";
 
 namespace {
 
 static PRTime
 GetTimestamp()
 {
   return PR_Now() / 1000;
 }
 
 static TraceInfo*
 AllocTraceInfo(int aTid)
 {
-  StaticMutexAutoLock lock(sMutex);
-
+  sMutex.AssertCurrentThreadOwns();
+  MOZ_ASSERT(sTraceInfos);
   auto* info = sTraceInfos->AppendElement(MakeUnique<TraceInfo>(aTid));
 
   return info->get();
 }
 
 static void
 CreateSourceEvent(SourceEventType aType)
 {
   // Create a new unique task id.
   uint64_t newId = GenNewUniqueTaskId();
-  TraceInfo* info = GetOrCreateTraceInfo();
-  ENSURE_TRUE_VOID(info);
+  {
+    TraceInfoHolder info = GetOrCreateTraceInfo();
+    ENSURE_TRUE_VOID(info);
 
-  info->mCurTraceSourceId = newId;
-  info->mCurTraceSourceType = aType;
-  info->mCurTaskId = newId;
+    info->mCurTraceSourceId = newId;
+    info->mCurTraceSourceType = aType;
+    info->mCurTaskId = newId;
+  }
 
   uintptr_t* namePtr;
 #define SOURCE_EVENT_NAME(type)         \
   case SourceEventType::type:           \
   {                                     \
     namePtr = (uintptr_t*)&CreateSourceEvent##type; \
     break;                              \
   }
@@ -113,50 +115,55 @@ CreateSourceEvent(SourceEventType aType)
   LogVirtualTablePtr(newId, newId, namePtr);
   LogBegin(newId, newId);
 }
 
 static void
 DestroySourceEvent()
 {
   // Log a fake end for this source event.
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
-  LogEnd(info->mCurTraceSourceId, info->mCurTraceSourceId);
+  uint64_t curTraceSourceId;
+  curTraceSourceId = info->mCurTraceSourceId;
+  info.Reset();
+
+  LogEnd(curTraceSourceId, curTraceSourceId);
+}
+
+inline static void
+ObsoleteCurrentTraceInfos()
+{
+  MOZ_ASSERT(sTraceInfos);
+  for (uint32_t i = 0; i < sTraceInfos->Length(); ++i) {
+    (*sTraceInfos)[i]->mObsolete = true;
+  }
 }
 
 inline static bool
 IsStartLogging()
 {
   return sStarted;
 }
 
 static void
 SetLogStarted(bool aIsStartLogging)
 {
   MOZ_ASSERT(aIsStartLogging != sStarted);
-  MOZ_ASSERT(sTraceInfos != nullptr);
+  StaticMutexAutoLock lock(sMutex);
+
   sStarted = aIsStartLogging;
 
-  StaticMutexAutoLock lock(sMutex);
-  if (!aIsStartLogging && sTraceInfos) {
-    for (uint32_t i = 0; i < sTraceInfos->Length(); ++i) {
-      (*sTraceInfos)[i]->mObsolete = true;
-    }
+  if (aIsStartLogging && sTraceInfos == nullptr) {
+    sTraceInfos = new nsTArray<UniquePtr<TraceInfo>>();
   }
-}
 
-inline static void
-ObsoleteCurrentTraceInfos()
-{
-  // Note that we can't and don't need to acquire sMutex here because this
-  // function is called before the other threads are recreated.
-  for (uint32_t i = 0; i < sTraceInfos->Length(); ++i) {
-    (*sTraceInfos)[i]->mObsolete = true;
+  if (!aIsStartLogging && sTraceInfos) {
+    ObsoleteCurrentTraceInfos();
   }
 }
 
 } // namespace anonymous
 
 TraceInfoLogType*
 TraceInfo::AppendLog()
 {
@@ -186,71 +193,83 @@ InitTaskTracer(uint32_t aFlags)
   }
 
   MOZ_ASSERT(!sTraceInfos);
 
   bool success = sTraceInfoTLS.init();
   if (!success) {
     MOZ_CRASH();
   }
-
-  // A memory barrier is necessary here.
-  sTraceInfos = new nsTArray<UniquePtr<TraceInfo>>();
 }
 
 void
 ShutdownTaskTracer()
 {
   if (IsStartLogging()) {
     SetLogStarted(false);
+
+    StaticMutexAutoLock lock(sMutex);
+    // Make sure all threads are out of holding mutics.
+    // See |GetOrCreateTraceInfo()|
+    for (auto& traceinfo: *sTraceInfos) {
+      MutexAutoLock lock(traceinfo->mLogsMutex);
+    }
+    delete sTraceInfos;
+    sTraceInfos = nullptr;
   }
 }
 
 static void
 FreeTraceInfo(TraceInfo* aTraceInfo)
 {
-  StaticMutexAutoLock lock(sMutex);
+  sMutex.AssertCurrentThreadOwns();
   if (aTraceInfo) {
     UniquePtr<TraceInfo> traceinfo(aTraceInfo);
     mozilla::DebugOnly<bool> removed =
       sTraceInfos->RemoveElement(traceinfo);
     MOZ_ASSERT(removed);
     Unused << traceinfo.release(); // A dirty hack to prevent double free.
   }
 }
 
 void FreeTraceInfo()
 {
-  FreeTraceInfo(sTraceInfoTLS.get());
+  StaticMutexAutoLock lock(sMutex);
+  if (sTraceInfos) {
+    FreeTraceInfo(sTraceInfoTLS.get());
+  }
 }
 
-TraceInfo*
+TraceInfoHolder
 GetOrCreateTraceInfo()
 {
-  ENSURE_TRUE(IsStartLogging(), nullptr);
+  TraceInfo* info = sTraceInfoTLS.get();
+  StaticMutexAutoLock lock(sMutex);
+  ENSURE_TRUE(IsStartLogging(), TraceInfoHolder{});
 
-  TraceInfo* info = sTraceInfoTLS.get();
   if (info && info->mObsolete) {
     // TraceInfo is obsolete: remove it.
     FreeTraceInfo(info);
     info = nullptr;
   }
 
   if (!info) {
     info = AllocTraceInfo(Thread::GetCurrentId());
     sTraceInfoTLS.set(info);
   }
 
-  return info;
+  return TraceInfoHolder{info}; // |mLogsMutex| will be held, then
+                                // ||sMutex| will be released for
+                                // efficiency reason.
 }
 
 uint64_t
 GenNewUniqueTaskId()
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE(info, 0);
 
   Thread::tid_t tid = Thread::GetCurrentId();
   uint64_t taskid = ((uint64_t)tid << 32) | ++info->mLastUniqueTaskId;
   return taskid;
 }
 
 AutoSaveCurTraceInfo::AutoSaveCurTraceInfo()
@@ -262,29 +281,29 @@ AutoSaveCurTraceInfo::~AutoSaveCurTraceI
 {
   SetCurTraceInfo(mSavedSourceEventId, mSavedTaskId, mSavedSourceEventType);
 }
 
 void
 SetCurTraceInfo(uint64_t aSourceEventId, uint64_t aParentTaskId,
                 SourceEventType aSourceEventType)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   info->mCurTraceSourceId = aSourceEventId;
   info->mCurTaskId = aParentTaskId;
   info->mCurTraceSourceType = aSourceEventType;
 }
 
 void
 GetCurTraceInfo(uint64_t* aOutSourceEventId, uint64_t* aOutParentTaskId,
                 SourceEventType* aOutSourceEventType)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   *aOutSourceEventId = info->mCurTraceSourceId;
   *aOutParentTaskId = info->mCurTaskId;
   *aOutSourceEventType = info->mCurTraceSourceType;
 }
 
 void
@@ -293,81 +312,77 @@ LogDispatch(uint64_t aTaskId, uint64_t a
 {
   LogDispatch(aTaskId, aParentTaskId, aSourceEventId, aSourceEventType, 0);
 }
 
 void
 LogDispatch(uint64_t aTaskId, uint64_t aParentTaskId, uint64_t aSourceEventId,
             SourceEventType aSourceEventType, int aDelayTimeMs)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   // aDelayTimeMs is the expected delay time in milliseconds, thus the dispatch
   // time calculated of it might be slightly off in the real world.
   uint64_t time = (aDelayTimeMs <= 0) ? GetTimestamp() :
                   GetTimestamp() + aDelayTimeMs;
 
-  MutexAutoLock lock(info->mLogsMutex);
   // Log format:
   // [0 taskId dispatchTime sourceEventId sourceEventType parentTaskId]
   TraceInfoLogType* log = info->AppendLog();
   if (log) {
     log->mDispatch.mType = ACTION_DISPATCH;
     log->mDispatch.mTaskId = aTaskId;
     log->mDispatch.mTime = time;
     log->mDispatch.mSourceEventId = aSourceEventId;
     log->mDispatch.mSourceEventType = aSourceEventType;
     log->mDispatch.mParentTaskId = aParentTaskId;
   }
 }
 
 void
 LogBegin(uint64_t aTaskId, uint64_t aSourceEventId)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
-  MutexAutoLock lock(info->mLogsMutex);
   // Log format:
   // [1 taskId beginTime processId threadId]
   TraceInfoLogType* log = info->AppendLog();
   if (log) {
     log->mBegin.mType = ACTION_BEGIN;
     log->mBegin.mTaskId = aTaskId;
     log->mBegin.mTime = GetTimestamp();
     log->mBegin.mPid = getpid();
     log->mBegin.mTid = Thread::GetCurrentId();
   }
 }
 
 void
 LogEnd(uint64_t aTaskId, uint64_t aSourceEventId)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
-  MutexAutoLock lock(info->mLogsMutex);
   // Log format:
   // [2 taskId endTime]
   TraceInfoLogType* log = info->AppendLog();
   if (log) {
     log->mEnd.mType = ACTION_END;
     log->mEnd.mTaskId = aTaskId;
     log->mEnd.mTime = GetTimestamp();
   }
 }
 
 void
 LogVirtualTablePtr(uint64_t aTaskId, uint64_t aSourceEventId, uintptr_t* aVptr)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
-  MutexAutoLock lock(info->mLogsMutex);
   // Log format:
   // [4 taskId address]
   TraceInfoLogType* log = info->AppendLog();
   if (log) {
     // Since addr2line used by the Gecko Profiler addon can not solve
     // non-function addresses, we use the first entry of vtable as the symbol
     // to solve. We should find a better solution later.
     log->mVPtr.mType = ACTION_GET_VTABLE;
@@ -407,20 +422,19 @@ AutoScopedLabel::~AutoScopedLabel()
   if (mLabel) {
     AddLabel("End %s", mLabel);
     free(mLabel);
   }
 }
 
 void AddLabel(const char* aFormat, ...)
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
-  MutexAutoLock lock(info->mLogsMutex);
   // Log format:
   // [3 taskId "label"]
   TraceInfoLogType* log = info->AppendLog();
   if (log) {
     va_list args;
     va_start(args, aFormat);
     nsCString &buffer = *info->mStrs.AppendElement();
     buffer.AppendPrintf(aFormat, args);
@@ -451,16 +465,20 @@ StopLogging()
 UniquePtr<nsTArray<nsCString>>
 GetLoggedData(TimeStamp aTimeStamp)
 {
   auto result = MakeUnique<nsTArray<nsCString>>();
 
   // TODO: This is called from a signal handler. Use semaphore instead.
   StaticMutexAutoLock lock(sMutex);
 
+  if (sTraceInfos == nullptr) {
+    return result;
+  }
+
   for (uint32_t i = 0; i < sTraceInfos->Length(); ++i) {
     TraceInfo* info = (*sTraceInfos)[i].get();
     MutexAutoLock lockLogs(info->mLogsMutex);
     if (info->mObsolete) {
       continue;
     }
 
     nsTArray<nsCString> &strs = info->mStrs;
--- a/tools/profiler/tasktracer/GeckoTaskTracerImpl.h
+++ b/tools/profiler/tasktracer/GeckoTaskTracerImpl.h
@@ -102,18 +102,53 @@ struct TraceInfo
   // This mutex protects the following log
   mozilla::Mutex mLogsMutex;
   TraceInfoLogNode* mLogsHead;
   TraceInfoLogNode* mLogsTail;
   int mLogsSize;
   nsTArray<nsCString> mStrs;
 };
 
+class TraceInfoHolder {
+public:
+  TraceInfoHolder() : mInfo(nullptr) {}
+  explicit TraceInfoHolder(TraceInfo* aInfo) : mInfo(aInfo) {
+    aInfo->mLogsMutex.AssertNotCurrentThreadOwns(); // in case of recursive
+    aInfo->mLogsMutex.Lock();
+    MOZ_ASSERT(aInfo);
+  }
+  TraceInfoHolder(const TraceInfoHolder& aOther) = delete;
+  TraceInfoHolder(TraceInfoHolder&& aOther) : mInfo(aOther.mInfo) {
+    if (!!aOther) {
+      aOther->mLogsMutex.AssertCurrentThreadOwns();
+    }
+    aOther.mInfo = nullptr;
+  }
+  ~TraceInfoHolder() { if (mInfo) mInfo->mLogsMutex.Unlock(); }
+  explicit operator bool() const { return !!mInfo; }
+  TraceInfo* operator ->() { return mInfo; }
+  bool operator ==(TraceInfo* aOther) const {
+    return mInfo == aOther;
+  }
+  bool operator ==(const TraceInfoHolder& aOther) const {
+    return mInfo == aOther.mInfo;
+  }
+  void Reset() {
+    if (mInfo) {
+      mInfo->mLogsMutex.Unlock();
+      mInfo = nullptr;
+    }
+  }
+
+private:
+  TraceInfo* mInfo;
+};
+
 // Return the TraceInfo of current thread, allocate a new one if not exit.
-TraceInfo* GetOrCreateTraceInfo();
+TraceInfoHolder GetOrCreateTraceInfo();
 
 uint64_t GenNewUniqueTaskId();
 
 void SetCurTraceInfo(uint64_t aSourceEventId, uint64_t aParentTaskId,
                      SourceEventType aSourceEventType);
 
 /**
  * Logging functions of different trace actions.
--- a/tools/profiler/tasktracer/TracedTaskCommon.cpp
+++ b/tools/profiler/tasktracer/TracedTaskCommon.cpp
@@ -29,17 +29,17 @@ TracedTaskCommon::TracedTaskCommon()
 
 TracedTaskCommon::~TracedTaskCommon()
 {
 }
 
 void
 TracedTaskCommon::Init()
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   mTaskId = GenNewUniqueTaskId();
   mSourceEventId = info->mCurTraceSourceId;
   mSourceEventType = info->mCurTraceSourceType;
   mParentTaskId = info->mCurTaskId;
   mIsTraceInfoInit = true;
 }
@@ -49,42 +49,42 @@ TracedTaskCommon::DispatchTask(int aDela
 {
   LogDispatch(mTaskId, mParentTaskId, mSourceEventId, mSourceEventType,
               aDelayTimeMs);
 }
 
 void
 TracedTaskCommon::GetTLSTraceInfo()
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   mSourceEventType = info->mCurTraceSourceType;
   mSourceEventId = info->mCurTraceSourceId;
   mTaskId = info->mCurTaskId;
   mIsTraceInfoInit = true;
 }
 
 void
 TracedTaskCommon::SetTLSTraceInfo()
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   if (mIsTraceInfoInit) {
     info->mCurTraceSourceId = mSourceEventId;
     info->mCurTraceSourceType = mSourceEventType;
     info->mCurTaskId = mTaskId;
   }
 }
 
 void
 TracedTaskCommon::ClearTLSTraceInfo()
 {
-  TraceInfo* info = GetOrCreateTraceInfo();
+  TraceInfoHolder info = GetOrCreateTraceInfo();
   ENSURE_TRUE_VOID(info);
 
   info->mCurTraceSourceId = 0;
   info->mCurTraceSourceType = SourceEventType::Unknown;
   info->mCurTaskId = 0;
 }
 
 /**