diff options
Diffstat (limited to 'tools/profiler/tasktracer')
-rw-r--r-- | tools/profiler/tasktracer/GeckoTaskTracer.cpp | 464 | ||||
-rw-r--r-- | tools/profiler/tasktracer/GeckoTaskTracer.h | 182 | ||||
-rw-r--r-- | tools/profiler/tasktracer/GeckoTaskTracerImpl.h | 180 | ||||
-rw-r--r-- | tools/profiler/tasktracer/SourceEventTypeMap.h | 16 | ||||
-rw-r--r-- | tools/profiler/tasktracer/TracedTaskCommon.cpp | 128 | ||||
-rw-r--r-- | tools/profiler/tasktracer/TracedTaskCommon.h | 130 |
6 files changed, 1100 insertions, 0 deletions
diff --git a/tools/profiler/tasktracer/GeckoTaskTracer.cpp b/tools/profiler/tasktracer/GeckoTaskTracer.cpp new file mode 100644 index 0000000000..5a8ca8625c --- /dev/null +++ b/tools/profiler/tasktracer/GeckoTaskTracer.cpp @@ -0,0 +1,464 @@ +/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ +/* vim:set ts=2 sw=2 sts=2 et cindent: */ +/* 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 "GeckoTaskTracer.h" +#include "GeckoTaskTracerImpl.h" + +#include "platform.h" + +#include "mozilla/DebugOnly.h" +#include "mozilla/MathAlgorithms.h" +#include "mozilla/StaticMutex.h" +#include "mozilla/ThreadLocal.h" +#include "mozilla/TimeStamp.h" +#include "mozilla/UniquePtr.h" +#include "mozilla/Unused.h" +#include "nsString.h" +#include "nsThreadUtils.h" +#include "prtime.h" + +#include <stdarg.h> + +#define MAX_SIZE_LOG (1024 * 128) + +// NS_ENSURE_TRUE_VOID() without the warning on the debug build. +#define ENSURE_TRUE_VOID(x) \ + do { \ + if (MOZ_UNLIKELY(!(x))) { \ + return; \ + } \ + } while (0) + +// NS_ENSURE_TRUE() without the warning on the debug build. +#define ENSURE_TRUE(x, ret) \ + do { \ + if (MOZ_UNLIKELY(!(x))) { \ + return ret; \ + } \ + } while (0) + +namespace mozilla { +namespace tasktracer { + +#define SOURCE_EVENT_NAME(type) \ + const char* CreateSourceEvent##type() { return "SourceEvent" #type; } +#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. +bool gStarted(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) { + 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(); + { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + 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; \ + } + + switch (aType) { +#include "SourceEventTypeMap.h" + default: + MOZ_CRASH("Unknown SourceEvent."); + } +#undef SOURCE_EVENT_NAME + + // Log a fake dispatch and start for this source event. + LogDispatch(newId, newId, newId, aType); + LogVirtualTablePtr(newId, newId, namePtr); + LogBegin(newId, newId); +} + +static void DestroySourceEvent() { + // Log a fake end for this source event. + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + 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; + } +} + +static void SetLogStarted(bool aIsStartLogging) { + MOZ_ASSERT(aIsStartLogging != gStarted); + StaticMutexAutoLock lock(sMutex); + + gStarted = aIsStartLogging; + + if (aIsStartLogging && sTraceInfos == nullptr) { + sTraceInfos = new nsTArray<UniquePtr<TraceInfo>>(); + } + + if (!aIsStartLogging && sTraceInfos) { + ObsoleteCurrentTraceInfos(); + } +} + +} // namespace + +TraceInfoLogType* TraceInfo::AppendLog() { + if (mLogsSize >= MAX_SIZE_LOG) { + return nullptr; + } + TraceInfoLogNode* node = new TraceInfoLogNode; + node->mNext = nullptr; + if (mLogsTail) { + mLogsTail->mNext = node; + mLogsTail = node; + } else { + mLogsTail = mLogsHead = node; + } + mLogsSize++; + return &node->mLog; +} + +void InitTaskTracer(uint32_t aFlags) { + StaticMutexAutoLock lock(sMutex); + + if (aFlags & FORKED_AFTER_NUWA) { + ObsoleteCurrentTraceInfos(); + return; + } + + MOZ_ASSERT(!sTraceInfos); + + bool success = sTraceInfoTLS.init(); + if (!success) { + MOZ_CRASH(); + } +} + +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) { + 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() { + StaticMutexAutoLock lock(sMutex); + if (sTraceInfos) { + FreeTraceInfo(sTraceInfoTLS.get()); + } +} + +TraceInfoHolder GetOrCreateTraceInfo() { + TraceInfo* info = sTraceInfoTLS.get(); + StaticMutexAutoLock lock(sMutex); + ENSURE_TRUE(IsStartLogging(), TraceInfoHolder{}); + + if (info && info->mObsolete) { + // TraceInfo is obsolete: remove it. + FreeTraceInfo(info); + info = nullptr; + } + + if (!info) { + info = AllocTraceInfo(profiler_current_thread_id()); + sTraceInfoTLS.set(info); + } + + return TraceInfoHolder{info}; // |mLogsMutex| will be held, then + // ||sMutex| will be released for + // efficiency reason. +} + +uint64_t GenNewUniqueTaskId() { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE(info, 0); + + int tid = profiler_current_thread_id(); + uint64_t taskid = ((uint64_t)tid << 32) | ++info->mLastUniqueTaskId; + return taskid; +} + +AutoSaveCurTraceInfoImpl::AutoSaveCurTraceInfoImpl() { + GetCurTraceInfo(&mSavedSourceEventId, &mSavedTaskId, &mSavedSourceEventType); +} + +AutoSaveCurTraceInfoImpl::~AutoSaveCurTraceInfoImpl() { + SetCurTraceInfo(mSavedSourceEventId, mSavedTaskId, mSavedSourceEventType); +} + +void SetCurTraceInfo(uint64_t aSourceEventId, uint64_t aParentTaskId, + SourceEventType aSourceEventType) { + 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) { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + *aOutSourceEventId = info->mCurTraceSourceId; + *aOutParentTaskId = info->mCurTaskId; + *aOutSourceEventType = info->mCurTraceSourceType; +} + +void LogDispatch(uint64_t aTaskId, uint64_t aParentTaskId, + uint64_t aSourceEventId, SourceEventType aSourceEventType) { + LogDispatch(aTaskId, aParentTaskId, aSourceEventId, aSourceEventType, 0); +} + +void LogDispatch(uint64_t aTaskId, uint64_t aParentTaskId, + uint64_t aSourceEventId, SourceEventType aSourceEventType, + int aDelayTimeMs) { + 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; + + // 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) { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + // 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 = profiler_current_process_id(); + log->mBegin.mTid = profiler_current_thread_id(); + + MOZ_ASSERT(log->mBegin.mPid >= 0, + "native process ID is < 0 (signed integer overflow)"); + MOZ_ASSERT(log->mBegin.mTid >= 0, + "native thread ID is < 0 (signed integer overflow)"); + } +} + +void LogEnd(uint64_t aTaskId, uint64_t aSourceEventId) { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + // 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) { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + // 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; + log->mVPtr.mTaskId = aTaskId; + log->mVPtr.mVPtr = reinterpret_cast<uintptr_t>(aVptr); + } +} + +void AutoSourceEvent::StartScope(SourceEventType aType) { + CreateSourceEvent(aType); +} + +void AutoSourceEvent::StopScope() { DestroySourceEvent(); } + +void AutoScopedLabel::Init(const char* aFormat, va_list& aArgs) { + nsCString label; + va_list& args = aArgs; + label.AppendPrintf(aFormat, args); + mLabel = strdup(label.get()); + AddLabel("Begin %s", mLabel); +} + +void DoAddLabel(const char* aFormat, va_list& aArgs) { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + // Log format: + // [3 taskId "label"] + TraceInfoLogType* log = info->AppendLog(); + if (log) { + va_list& args = aArgs; + nsCString& buffer = *info->mStrs.AppendElement(); + buffer.AppendPrintf(aFormat, args); + + log->mLabel.mType = ACTION_ADD_LABEL; + log->mLabel.mTaskId = info->mCurTaskId; + log->mLabel.mTime = GetTimestamp(); + log->mLabel.mStrIdx = info->mStrs.Length() - 1; + } +} + +// Functions used by GeckoProfiler. + +void StartLogging() { + sStartTime = GetTimestamp(); + SetLogStarted(true); +} + +void StopLogging() { SetLogStarted(false); } + +UniquePtr<Vector<nsCString>> GetLoggedData(TimeStamp aTimeStamp) { + auto result = MakeUnique<Vector<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; + for (TraceInfoLogNode* node = info->mLogsHead; node; node = node->mNext) { + TraceInfoLogType& log = node->mLog; + MOZ_RELEASE_ASSERT(result->append(nsCString())); + nsCString& buffer = result->back(); + + switch (log.mType) { + case ACTION_DISPATCH: + buffer.AppendPrintf("%d %llu %llu %llu %d %llu", ACTION_DISPATCH, + (unsigned long long)log.mDispatch.mTaskId, + (unsigned long long)log.mDispatch.mTime, + (unsigned long long)log.mDispatch.mSourceEventId, + log.mDispatch.mSourceEventType, + (unsigned long long)log.mDispatch.mParentTaskId); + break; + + case ACTION_BEGIN: + buffer.AppendPrintf("%d %llu %llu %d %d", ACTION_BEGIN, + (unsigned long long)log.mBegin.mTaskId, + (unsigned long long)log.mBegin.mTime, + log.mBegin.mPid, log.mBegin.mTid); + break; + + case ACTION_END: + buffer.AppendPrintf("%d %llu %llu", ACTION_END, + (unsigned long long)log.mEnd.mTaskId, + (unsigned long long)log.mEnd.mTime); + break; + + case ACTION_GET_VTABLE: + buffer.AppendPrintf("%d %llu %p", ACTION_GET_VTABLE, + (unsigned long long)log.mVPtr.mTaskId, + (void*)log.mVPtr.mVPtr); + break; + + case ACTION_ADD_LABEL: + buffer.AppendPrintf("%d %llu %llu2 \"%s\"", ACTION_ADD_LABEL, + (unsigned long long)log.mLabel.mTaskId, + (unsigned long long)log.mLabel.mTime, + strs[log.mLabel.mStrIdx].get()); + break; + + default: + MOZ_CRASH("Unknow TaskTracer log type!"); + } + } + } + + return result; +} + +PRTime GetStartTime() { return sStartTime; } + +const char* GetJSLabelPrefix() { return sJSLabelPrefix; } + +#undef ENSURE_TRUE_VOID +#undef ENSURE_TRUE + +} // namespace tasktracer +} // namespace mozilla diff --git a/tools/profiler/tasktracer/GeckoTaskTracer.h b/tools/profiler/tasktracer/GeckoTaskTracer.h new file mode 100644 index 0000000000..dc299ac8fd --- /dev/null +++ b/tools/profiler/tasktracer/GeckoTaskTracer.h @@ -0,0 +1,182 @@ +/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ +/* vim:set ts=2 sw=2 sts=2 et cindent: */ +/* 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 GECKO_TASK_TRACER_H +#define GECKO_TASK_TRACER_H + +#include "mozilla/Atomics.h" +#include "mozilla/Maybe.h" +#include "mozilla/UniquePtr.h" +#include "mozilla/Vector.h" +#include "nsCOMPtr.h" +#include "nsStringFwd.h" + +#include <stdarg.h> + +/** + * TaskTracer provides a way to trace the correlation between different tasks + * across threads and processes. Unlike sampling based profilers, TaskTracer can + * tell you where a task is dispatched from, what its original source was, how + * long it waited in the event queue, and how long it took to execute. + * + * Source Events are usually some kinds of I/O events we're interested in, such + * as touch events, timer events, network events, etc. When a source event is + * created, TaskTracer records the entire chain of Tasks and nsRunnables as they + * are dispatched to different threads and processes. It records latency, + * execution time, etc. for each Task and nsRunnable that chains back to the + * original source event. + */ + +class nsIRunnable; + +namespace mozilla { + +class TimeStamp; +class Runnable; + +namespace tasktracer { + +extern bool gStarted; + +/** + * Check if the TaskTracer has been started. + */ +inline bool IsStartLogging() { + // |gStarted| is not an atomic variable, but it is fine for it is a + // boolean value and will be changed under the protection of + // |sMutex|. + // + // There is a latency between the change of the value and the + // observation of threads. |gStarted| would be checked again with + // the protection of mutex in logging functions; for example, + // |AddLabel()|, so all false positive would be blocked with the + // double checks. For false negative, it is fine to lose some + // records at begin of logging. + return gStarted; +} + +enum { FORKED_AFTER_NUWA = 1 << 0 }; + +enum SourceEventType { +#define SOURCE_EVENT_NAME(x) x, +#include "SourceEventTypeMap.h" +#undef SOURCE_EVENT_NAME +}; + +class AutoSaveCurTraceInfoImpl { + uint64_t mSavedTaskId; + uint64_t mSavedSourceEventId; + SourceEventType mSavedSourceEventType; + + public: + AutoSaveCurTraceInfoImpl(); + ~AutoSaveCurTraceInfoImpl(); +}; + +class AutoSaveCurTraceInfo { + Maybe<AutoSaveCurTraceInfoImpl> mSaved; + + public: + AutoSaveCurTraceInfo() { + if (IsStartLogging()) { + mSaved.emplace(); + } + } + + /** + * The instance had saved TraceInfo. + * + * It means that TaskTrace had been enabled when the instance was + * created. + */ + bool HasSavedTraceInfo() { return !!mSaved; } +}; + +class AutoSourceEvent : public AutoSaveCurTraceInfo { + void StartScope(SourceEventType aType); + void StopScope(); + + public: + explicit AutoSourceEvent(SourceEventType aType) : AutoSaveCurTraceInfo() { + if (HasSavedTraceInfo()) { + StartScope(aType); + } + } + + ~AutoSourceEvent() { + if (HasSavedTraceInfo()) { + StopScope(); + } + } +}; + +void InitTaskTracer(uint32_t aFlags = 0); +void ShutdownTaskTracer(); + +void DoAddLabel(const char* aFormat, va_list& aArgs); + +// Add a label to the currently running task, aFormat is the message to log, +// followed by corresponding parameters. +inline void AddLabel(const char* aFormat, ...) MOZ_FORMAT_PRINTF(1, 2); +inline void AddLabel(const char* aFormat, ...) { + if (IsStartLogging()) { + va_list args; + va_start(args, aFormat); + DoAddLabel(aFormat, args); + va_end(args); + } +} + +void StartLogging(); +void StopLogging(); +UniquePtr<Vector<nsCString>> GetLoggedData(TimeStamp aStartTime); + +// Returns the timestamp when Task Tracer is enabled in this process. +PRTime GetStartTime(); + +/** + * Internal functions. + */ + +already_AddRefed<nsIRunnable> CreateTracedRunnable( + already_AddRefed<nsIRunnable>&& aRunnable); + +// Free the TraceInfo allocated on a thread's TLS. Currently we are wrapping +// tasks running on nsThreads and base::thread, so FreeTraceInfo is called at +// where nsThread and base::thread release themselves. +void FreeTraceInfo(); + +const char* GetJSLabelPrefix(); + +void GetCurTraceInfo(uint64_t* aOutSourceEventId, uint64_t* aOutParentTaskId, + SourceEventType* aOutSourceEventType); + +class AutoScopedLabel { + char* mLabel; + void Init(const char* aFormat, va_list& aArgs); + + public: + explicit AutoScopedLabel(const char* aFormat, ...) : mLabel(nullptr) { + if (IsStartLogging()) { + va_list args; + va_start(args, aFormat); + Init(aFormat, args); + va_end(args); + } + } + + ~AutoScopedLabel() { + if (mLabel) { + AddLabel("End %s", mLabel); + free(mLabel); + } + } +}; + +} // namespace tasktracer +} // namespace mozilla. + +#endif diff --git a/tools/profiler/tasktracer/GeckoTaskTracerImpl.h b/tools/profiler/tasktracer/GeckoTaskTracerImpl.h new file mode 100644 index 0000000000..2b44a0f904 --- /dev/null +++ b/tools/profiler/tasktracer/GeckoTaskTracerImpl.h @@ -0,0 +1,180 @@ +/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ +/* vim:set ts=2 sw=2 sts=2 et cindent: */ +/* 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 GECKO_TASK_TRACER_IMPL_H +#define GECKO_TASK_TRACER_IMPL_H + +#include "GeckoTaskTracer.h" + +#include "mozilla/Mutex.h" +#include "nsTArray.h" + +namespace mozilla { +namespace tasktracer { + +struct LogRecDispatch { + uint32_t mType; + uint32_t mSourceEventType; + uint64_t mTaskId; + uint64_t mTime; + uint64_t mSourceEventId; + uint64_t mParentTaskId; +}; + +struct LogRecBegin { + uint32_t mType; + uint64_t mTaskId; + uint64_t mTime; + uint32_t mPid; + uint32_t mTid; +}; + +struct LogRecEnd { + uint32_t mType; + uint64_t mTaskId; + uint64_t mTime; +}; + +struct LogRecVPtr { + uint32_t mType; + uint64_t mTaskId; + uintptr_t mVPtr; +}; + +struct LogRecLabel { + uint32_t mType; + uint32_t mStrIdx; + uint64_t mTaskId; + uint64_t mTime; +}; + +union TraceInfoLogType { + uint32_t mType; + LogRecDispatch mDispatch; + LogRecBegin mBegin; + LogRecEnd mEnd; + LogRecVPtr mVPtr; + LogRecLabel mLabel; +}; + +struct TraceInfoLogNode { + TraceInfoLogType mLog; + TraceInfoLogNode* mNext; +}; + +struct TraceInfo { + explicit TraceInfo(uint32_t aThreadId) + : mCurTraceSourceId(0), + mCurTaskId(0), + mCurTraceSourceType(Unknown), + mThreadId(aThreadId), + mLastUniqueTaskId(0), + mObsolete(false), + mLogsMutex("TraceInfoMutex"), + mLogsHead(nullptr), + mLogsTail(nullptr), + mLogsSize(0) { + MOZ_COUNT_CTOR(TraceInfo); + } + + ~TraceInfo() { + MOZ_COUNT_DTOR(TraceInfo); + while (mLogsHead) { + auto node = mLogsHead; + mLogsHead = node->mNext; + delete node; + } + } + + TraceInfoLogType* AppendLog(); + + uint64_t mCurTraceSourceId; + uint64_t mCurTaskId; + SourceEventType mCurTraceSourceType; + uint32_t mThreadId; + uint32_t mLastUniqueTaskId; + mozilla::Atomic<bool> mObsolete; + + // 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. +TraceInfoHolder GetOrCreateTraceInfo(); + +uint64_t GenNewUniqueTaskId(); + +void SetCurTraceInfo(uint64_t aSourceEventId, uint64_t aParentTaskId, + SourceEventType aSourceEventType); + +/** + * Logging functions of different trace actions. + */ +enum ActionType { + ACTION_DISPATCH = 0, + ACTION_BEGIN, + ACTION_END, + ACTION_ADD_LABEL, + ACTION_GET_VTABLE +}; + +void LogDispatch(uint64_t aTaskId, uint64_t aParentTaskId, + uint64_t aSourceEventId, SourceEventType aSourceEventType); + +void LogDispatch(uint64_t aTaskId, uint64_t aParentTaskId, + uint64_t aSourceEventId, SourceEventType aSourceEventType, + int aDelayTimeMs); + +void LogBegin(uint64_t aTaskId, uint64_t aSourceEventId); + +void LogEnd(uint64_t aTaskId, uint64_t aSourceEventId); + +void LogVirtualTablePtr(uint64_t aTaskId, uint64_t aSourceEventId, + uintptr_t* aVptr); + +} // namespace tasktracer +} // namespace mozilla + +#endif diff --git a/tools/profiler/tasktracer/SourceEventTypeMap.h b/tools/profiler/tasktracer/SourceEventTypeMap.h new file mode 100644 index 0000000000..6e687ecb1e --- /dev/null +++ b/tools/profiler/tasktracer/SourceEventTypeMap.h @@ -0,0 +1,16 @@ +/* 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 GECKO_TASK_TRACER_H +# error "Don't include this file directly" +#endif + +SOURCE_EVENT_NAME(Unknown) +SOURCE_EVENT_NAME(Touch) +SOURCE_EVENT_NAME(Mouse) +SOURCE_EVENT_NAME(Key) +SOURCE_EVENT_NAME(Bluetooth) +SOURCE_EVENT_NAME(Unixsocket) +SOURCE_EVENT_NAME(Wifi) +SOURCE_EVENT_NAME(SocketIO) diff --git a/tools/profiler/tasktracer/TracedTaskCommon.cpp b/tools/profiler/tasktracer/TracedTaskCommon.cpp new file mode 100644 index 0000000000..4b5d4d4cc6 --- /dev/null +++ b/tools/profiler/tasktracer/TracedTaskCommon.cpp @@ -0,0 +1,128 @@ +/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ +/* vim:set ts=2 sw=2 sts=2 et cindent: */ +/* 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 "TracedTaskCommon.h" + +#include "GeckoTaskTracerImpl.h" + +// NS_ENSURE_TRUE_VOID() without the warning on the debug build. +#define ENSURE_TRUE_VOID(x) \ + do { \ + if (MOZ_UNLIKELY(!(x))) { \ + return; \ + } \ + } while (0) + +namespace mozilla { +namespace tasktracer { + +TracedTaskCommon::TracedTaskCommon() + : mSourceEventType(SourceEventType::Unknown), + mSourceEventId(0), + mParentTaskId(0), + mTaskId(0), + mIsTraceInfoInit(false) {} + +TracedTaskCommon::~TracedTaskCommon() {} + +void TracedTaskCommon::Init() { + // Keep the following line before GetOrCreateTraceInfo() to avoid a + // deadlock. + uint64_t taskid = GenNewUniqueTaskId(); + + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + mTaskId = taskid; + mSourceEventId = info->mCurTraceSourceId; + mSourceEventType = info->mCurTraceSourceType; + mParentTaskId = info->mCurTaskId; + mIsTraceInfoInit = true; +} + +void TracedTaskCommon::DispatchTask(int aDelayTimeMs) { + LogDispatch(mTaskId, mParentTaskId, mSourceEventId, mSourceEventType, + aDelayTimeMs); +} + +void TracedTaskCommon::DoGetTLSTraceInfo() { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + MOZ_ASSERT(!mIsTraceInfoInit); + + mSourceEventType = info->mCurTraceSourceType; + mSourceEventId = info->mCurTraceSourceId; + mTaskId = info->mCurTaskId; + mIsTraceInfoInit = true; +} + +void TracedTaskCommon::DoSetTLSTraceInfo() { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + if (mIsTraceInfoInit) { + info->mCurTraceSourceId = mSourceEventId; + info->mCurTraceSourceType = mSourceEventType; + info->mCurTaskId = mTaskId; + } +} + +void TracedTaskCommon::ClearTLSTraceInfo() { + TraceInfoHolder info = GetOrCreateTraceInfo(); + ENSURE_TRUE_VOID(info); + + info->mCurTraceSourceId = 0; + info->mCurTraceSourceType = SourceEventType::Unknown; + info->mCurTaskId = 0; +} + +/** + * Implementation of class TracedRunnable. + */ + +NS_IMPL_ISUPPORTS(TracedRunnable, nsIRunnable); + +TracedRunnable::TracedRunnable(already_AddRefed<nsIRunnable>&& aOriginalObj) + : TracedTaskCommon(), mOriginalObj(std::move(aOriginalObj)) { + Init(); + LogVirtualTablePtr(mTaskId, mSourceEventId, + *reinterpret_cast<uintptr_t**>(mOriginalObj.get())); +} + +TracedRunnable::~TracedRunnable() {} + +NS_IMETHODIMP +TracedRunnable::Run() { + SetTLSTraceInfo(); + LogBegin(mTaskId, mSourceEventId); + nsresult rv = mOriginalObj->Run(); + LogEnd(mTaskId, mSourceEventId); + ClearTLSTraceInfo(); + + return rv; +} + +/** + * CreateTracedRunnable() returns a TracedRunnable wrapping the original + * nsIRunnable object, aRunnable. + */ +already_AddRefed<nsIRunnable> CreateTracedRunnable( + already_AddRefed<nsIRunnable>&& aRunnable) { + RefPtr<nsIRunnable> runnable = new TracedRunnable(std::move(aRunnable)); + return runnable.forget(); +} + +void VirtualTask::AutoRunTask::StartScope(VirtualTask* aTask) { + mTask->SetTLSTraceInfo(); + LogBegin(mTask->mTaskId, mTask->mSourceEventId); +} + +void VirtualTask::AutoRunTask::StopScope() { + LogEnd(mTask->mTaskId, mTask->mSourceEventId); +} + +} // namespace tasktracer +} // namespace mozilla diff --git a/tools/profiler/tasktracer/TracedTaskCommon.h b/tools/profiler/tasktracer/TracedTaskCommon.h new file mode 100644 index 0000000000..d93e1b38e7 --- /dev/null +++ b/tools/profiler/tasktracer/TracedTaskCommon.h @@ -0,0 +1,130 @@ +/* -*- Mode: C++; tab-width: 2; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ +/* vim:set ts=2 sw=2 sts=2 et cindent: */ +/* 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 TRACED_TASK_COMMON_H +#define TRACED_TASK_COMMON_H + +#include "GeckoTaskTracer.h" + +#include "nsCOMPtr.h" +#include "nsThreadUtils.h" + +namespace mozilla { +namespace tasktracer { + +class TracedTaskCommon { + public: + TracedTaskCommon(); + TracedTaskCommon(const TracedTaskCommon& aSrc) + : mSourceEventType(aSrc.mSourceEventType), + mSourceEventId(aSrc.mSourceEventId), + mParentTaskId(aSrc.mParentTaskId), + mTaskId(aSrc.mTaskId), + mIsTraceInfoInit(aSrc.mIsTraceInfoInit) {} + virtual ~TracedTaskCommon(); + + void DispatchTask(int aDelayTimeMs = 0); + + void SetTLSTraceInfo() { + if (mIsTraceInfoInit) { + DoSetTLSTraceInfo(); + } + } + void GetTLSTraceInfo() { + if (IsStartLogging()) { + DoGetTLSTraceInfo(); + } + } + void ClearTLSTraceInfo(); + + private: + void DoSetTLSTraceInfo(); + void DoGetTLSTraceInfo(); + + protected: + void Init(); + + // TraceInfo of TLS will be set by the following parameters, including source + // event type, source event ID, parent task ID, and task ID of this traced + // task/runnable. + SourceEventType mSourceEventType; + uint64_t mSourceEventId; + uint64_t mParentTaskId; + uint64_t mTaskId; + bool mIsTraceInfoInit; +}; + +class TracedRunnable : public TracedTaskCommon, public nsIRunnable { + public: + NS_DECL_THREADSAFE_ISUPPORTS + NS_DECL_NSIRUNNABLE + + explicit TracedRunnable(already_AddRefed<nsIRunnable>&& aOriginalObj); + + private: + virtual ~TracedRunnable(); + + nsCOMPtr<nsIRunnable> mOriginalObj; +}; + +/** + * This class is used to create a logical task, without a real + * runnable. + */ +class VirtualTask : public TracedTaskCommon { + public: + VirtualTask() : TracedTaskCommon() {} + + VirtualTask(const VirtualTask& aSrc) : TracedTaskCommon(aSrc) {} + + /** + * Initialize the task to create an unique ID, and store other + * information. + * + * This method may be called for one or more times. + */ + void Init(uintptr_t* aVPtr = nullptr) { + TracedTaskCommon::Init(); + if (aVPtr) { + extern void LogVirtualTablePtr(uint64_t aTaskId, uint64_t aSourceEventId, + uintptr_t * aVptr); + LogVirtualTablePtr(mTaskId, mSourceEventId, aVPtr); + } + DispatchTask(); + } + + /** + * Define the life-span of a VirtualTask. + * + * VirtualTask is not a real task, goes without a runnable, it's + * instances are never dispatched and ran by event loops. This + * class used to define running time as the life-span of it's + * instance. + */ + class AutoRunTask : public AutoSaveCurTraceInfo { + VirtualTask* mTask; + void StartScope(VirtualTask* aTask); + void StopScope(); + + public: + explicit AutoRunTask(VirtualTask* aTask) + : AutoSaveCurTraceInfo(), mTask(aTask) { + if (HasSavedTraceInfo()) { + StartScope(aTask); + } + } + ~AutoRunTask() { + if (HasSavedTraceInfo()) { + StopScope(); + } + } + }; +}; + +} // namespace tasktracer +} // namespace mozilla + +#endif |