The Tor Browser: comparison xpcom/base/VisualEventTracer.cpp

--1:000000000000
+:36f8d952f5b6
+/* 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 "mozilla/VisualEventTracer.h"
+#include "mozilla/Monitor.h"
+#include "mozilla/TimeStamp.h"
+#include "nscore.h"
+#include "prthread.h"
+#include "prprf.h"
+#include "prenv.h"
+#include "plstr.h"
+#include "nsThreadUtils.h"
+namespace mozilla { namespace eventtracer {
+#ifdef MOZ_VISUAL_EVENT_TRACER
+namespace {
+const uint32_t kBatchSize = 256;
+const char kTypeChars[eventtracer::eLast] = {' ','N','S','W','E','D'};
+// Flushing thread and records queue monitor
+mozilla::Monitor * gMonitor = nullptr;
+// gInitialized and gCapture can be accessed from multiple threads
+// simultaneously without any locking.  However, since they are only ever
+// *set* from the main thread, the chance of races manifesting is small
+// and unlikely to be a problem in practice.
+bool gInitialized;
+// Flag to allow capturing
+bool gCapture;
+// Time stamp of the epoch we have started to capture
+mozilla::TimeStamp * gProfilerStart;
+// Duration of the log to keep up to
+mozilla::TimeDuration * gMaxBacklogTime;
+// Record of a single event
+class Record {
+public:
+Record()
+: mType(::mozilla::eventtracer::eNone)
+, mItem(nullptr)
+, mText(nullptr)
+, mText2(nullptr)
+{
+MOZ_COUNT_CTOR(Record);
+}
+Record& operator=(const Record & aOther)
+{
+mType = aOther.mType;
+mTime = aOther.mTime;
+mItem = aOther.mItem;
+mText = PL_strdup(aOther.mText);
+mText2 = aOther.mText2 ? PL_strdup(aOther.mText2) : nullptr;
+return *this;
+}
+~Record()
+{
+PL_strfree(mText2);
+PL_strfree(mText);
+MOZ_COUNT_DTOR(Record);
+}
+uint32_t mType;
+TimeStamp mTime;
+void * mItem;
+char * mText;
+char * mText2;
+};
+char * DupCurrentThreadName()
+{
+if (NS_IsMainThread())
+return PL_strdup("Main Thread");
+PRThread * currentThread = PR_GetCurrentThread();
+const char * name = PR_GetThreadName(currentThread);
+if (name)
+return PL_strdup(name);
+char buffer[128];
+PR_snprintf(buffer, 127, "Nameless %p", currentThread);
+return PL_strdup(buffer);
+}
+// An array of events, each thread keeps its own private instance
+class RecordBatch {
+public:
+RecordBatch(size_t aLength = kBatchSize,
+char * aThreadName = DupCurrentThreadName())
+: mRecordsHead(new Record[aLength])
+, mRecordsTail(mRecordsHead + aLength)
+, mNextRecord(mRecordsHead)
+, mNextBatch(nullptr)
+, mThreadNameCopy(aThreadName)
+, mClosed(false)
+{
+MOZ_COUNT_CTOR(RecordBatch);
+}
+~RecordBatch()
+{
+delete [] mRecordsHead;
+PL_strfree(mThreadNameCopy);
+MOZ_COUNT_DTOR(RecordBatch);
+}
+void Close() { mClosed = true; }
+size_t Length() const { return mNextRecord - mRecordsHead; }
+bool CanBeDeleted(const TimeStamp& aUntil) const;
+static RecordBatch * Register();
+static void Close(void * data); // Registered on freeing thread data
+static RecordBatch * Clone(RecordBatch * aLog, const TimeStamp& aSince);
+static void Delete(RecordBatch * aLog);
+static RecordBatch * CloneLog();
+static void GCLog(const TimeStamp& aUntil);
+static void DeleteLog();
+Record * mRecordsHead;
+Record * mRecordsTail;
+Record * mNextRecord;
+RecordBatch * mNextBatch;
+char * mThreadNameCopy;
+bool mClosed;
+};
+// Protected by gMonitor, accessed concurently
+// Linked list of batches threads want to flush on disk
+RecordBatch * gLogHead = nullptr;
+RecordBatch * gLogTail = nullptr;
+// Registers the batch in the linked list
+// static
+RecordBatch *
+RecordBatch::Register()
+{
+MonitorAutoLock mon(*gMonitor);
+if (!gInitialized)
+return nullptr;
+if (gLogHead)
+RecordBatch::GCLog(TimeStamp::Now() - *gMaxBacklogTime);
+RecordBatch * batch = new RecordBatch();
+if (!gLogHead)
+gLogHead = batch;
+else // gLogTail is non-null
+gLogTail->mNextBatch = batch;
+gLogTail = batch;
+mon.Notify();
+return batch;
+}
+void
+RecordBatch::Close(void * data)
+{
+RecordBatch * batch = static_cast<RecordBatch*>(data);
+batch->Close();
+}
+// static
+RecordBatch *
+RecordBatch::Clone(RecordBatch * aOther, const TimeStamp& aSince)
+{
+if (!aOther)
+return nullptr;
+size_t length = aOther->Length();
+size_t min = 0;
+size_t max = length;
+Record * record = nullptr;
+// Binary search for record with time >= aSince
+size_t i;
+while (min < max) {
+i = (max + min) / 2;
+record = aOther->mRecordsHead + i;
+if (record->mTime >= aSince)
+max = i;
+else
+min = i+1;
+}
+i = (max + min) / 2;
+// How many Record's to copy?
+size_t toCopy = length - i;
+if (!toCopy)
+return RecordBatch::Clone(aOther->mNextBatch, aSince);
+// Clone
+RecordBatch * clone = new RecordBatch(toCopy, PL_strdup(aOther->mThreadNameCopy));
+for (; i < length; ++i) {
+record = aOther->mRecordsHead + i;
+*clone->mNextRecord = *record;
+++clone->mNextRecord;
+}
+clone->mNextBatch = RecordBatch::Clone(aOther->mNextBatch, aSince);
+return clone;
+}
+// static
+void
+RecordBatch::Delete(RecordBatch * aLog)
+{
+while (aLog) {
+RecordBatch * batch = aLog;
+aLog = aLog->mNextBatch;
+delete batch;
+}
+}
+// static
+RecordBatch *
+RecordBatch::CloneLog()
+{
+TimeStamp startEpoch = *gProfilerStart;
+TimeStamp backlogEpoch = TimeStamp::Now() - *gMaxBacklogTime;
+TimeStamp since = (startEpoch > backlogEpoch) ? startEpoch : backlogEpoch;
+MonitorAutoLock mon(*gMonitor);
+return RecordBatch::Clone(gLogHead, since);
+}
+// static
+void
+RecordBatch::GCLog(const TimeStamp& aUntil)
+{
+// Garbage collect all unreferenced and old batches
+gMonitor->AssertCurrentThreadOwns();
+RecordBatch *volatile * referer = &gLogHead;
+gLogTail = nullptr;
+RecordBatch * batch = *referer;
+while (batch) {
+if (batch->CanBeDeleted(aUntil)) {
+// The batch is completed and thus unreferenced by the thread
+// and the most recent record has time older then the time
+// we want to save records for, hence delete it.
+*referer = batch->mNextBatch;
+delete batch;
+batch = *referer;
+}
+else {
+// We walk the whole list, so this will end up filled with
+// the very last valid element of it.
+gLogTail = batch;
+// The current batch is active, examine the next in the list.
+batch = batch->mNextBatch;
+// When the next batch is found expired, we must extract it
+// from the list, shift the referer.
+referer = &((*referer)->mNextBatch);
+}
+}
+}
+// static
+void
+RecordBatch::DeleteLog()
+{
+RecordBatch * batch;
+{
+MonitorAutoLock mon(*gMonitor);
+batch = gLogHead;
+gLogHead = nullptr;
+gLogTail = nullptr;
+}
+RecordBatch::Delete(batch);
+}
+bool
+RecordBatch::CanBeDeleted(const TimeStamp& aUntil) const
+{
+if (mClosed) {
+// This flag is set when a thread releases this batch as
+// its private data.  It happens when the list is full or
+// when the thread ends its job.  We must not delete this
+// batch from memory while it's held by a thread.
+if (!Length()) {
+// There are no records, just get rid of this empty batch.
+return true;
+}
+if ((mNextRecord-1)->mTime <= aUntil) {
+// Is the last record older then the time we demand records
+// for?  If not, this batch has expired.
+return true;
+}
+}
+// Not all conditions to close the batch met, keep it.
+return false;
+}
+// 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 nullptr;
+// Reads a comma serpatated list of events.
+// Copied from nspr logging code (read of NSPR_LOG_MODULES)
+char eventName[64];
+int 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 nullptr;
+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 and control variables, initialized in Init() method, after it
+// immutable and read concurently.
+EventFilter * gEventFilter = nullptr;
+unsigned gThreadPrivateIndex;
+// static
+bool CheckEventFilters(uint32_t aType, void * aItem, const char * aText)
+{
+if (!gEventFilter)
+return true;
+if (aType == eName)
+return true;
+return gEventFilter->EventPasses(aText);
+}
+} // anon namespace
+#endif //MOZ_VISUAL_EVENT_TRACER
+// static
+void Init()
+{
+#ifdef MOZ_VISUAL_EVENT_TRACER
+const char * logEvents = PR_GetEnv("MOZ_PROFILING_EVENTS");
+if (logEvents && *logEvents)
+gEventFilter = EventFilter::Build(logEvents);
+PRStatus status = PR_NewThreadPrivateIndex(&gThreadPrivateIndex, &RecordBatch::Close);
+if (status != PR_SUCCESS)
+return;
+gMonitor = new mozilla::Monitor("Profiler");
+if (!gMonitor)
+return;
+gProfilerStart = new mozilla::TimeStamp();
+gMaxBacklogTime = new mozilla::TimeDuration();
+gInitialized = true;
+#endif
+}
+// static
+void Shutdown()
+{
+#ifdef MOZ_VISUAL_EVENT_TRACER
+gCapture = false;
+gInitialized = false;
+RecordBatch::DeleteLog();
+if (gMonitor) {
+delete gMonitor;
+gMonitor = nullptr;
+}
+if (gEventFilter) {
+delete gEventFilter;
+gEventFilter = nullptr;
+}
+if (gProfilerStart) {
+delete gProfilerStart;
+gProfilerStart = nullptr;
+}
+if (gMaxBacklogTime) {
+delete gMaxBacklogTime;
+gMaxBacklogTime = nullptr;
+}
+#endif
+}
+// static
+void Mark(uint32_t aType, void * aItem, const char * aText, const char * aText2)
+{
+#ifdef MOZ_VISUAL_EVENT_TRACER
+if (!gInitialized || !gCapture)
+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) {
+threadLogPrivate = RecordBatch::Register();
+if (!threadLogPrivate)
+return;
+PR_SetThreadPrivate(gThreadPrivateIndex, threadLogPrivate);
+}
+Record * record = threadLogPrivate->mNextRecord;
+record->mType = aType;
+record->mTime = mozilla::TimeStamp::Now();
+record->mItem = aItem;
+record->mText = PL_strdup(aText);
+record->mText2 = aText2 ? PL_strdup(aText2) : nullptr;
+++threadLogPrivate->mNextRecord;
+if (threadLogPrivate->mNextRecord == threadLogPrivate->mRecordsTail) {
+// Calls RecordBatch::Close(threadLogPrivate) that marks
+// the batch as OK to be deleted from memory when no longer needed.
+PR_SetThreadPrivate(gThreadPrivateIndex, nullptr);
+}
+#endif
+}
+#ifdef MOZ_VISUAL_EVENT_TRACER
+// The scriptable classes
+class VisualEventTracerLog : public nsIVisualEventTracerLog
+{
+NS_DECL_ISUPPORTS
+NS_DECL_NSIVISUALEVENTTRACERLOG
+VisualEventTracerLog(RecordBatch* aBatch)
+: mBatch(aBatch)
+, mProfilerStart(*gProfilerStart)
+{}
+virtual ~VisualEventTracerLog();
+protected:
+RecordBatch * mBatch;
+TimeStamp mProfilerStart;
+};
+NS_IMPL_ISUPPORTS(VisualEventTracerLog, nsIVisualEventTracerLog)
+VisualEventTracerLog::~VisualEventTracerLog()
+{
+RecordBatch::Delete(mBatch);
+}
+NS_IMETHODIMP
+VisualEventTracerLog::GetJSONString(nsACString & _retval)
+{
+nsCString buffer;
+buffer.Assign(NS_LITERAL_CSTRING("{\n\"version\": 1,\n\"records\":[\n"));
+RecordBatch * batch = mBatch;
+while (batch) {
+if (batch != mBatch) {
+// This is not the first batch we are writting, add comma
+buffer.Append(NS_LITERAL_CSTRING(",\n"));
+}
+buffer.Append(NS_LITERAL_CSTRING("{\"thread\":\""));
+buffer.Append(batch->mThreadNameCopy);
+buffer.Append(NS_LITERAL_CSTRING("\",\"log\":[\n"));
+static const int kBufferSize = 2048;
+char buf[kBufferSize];
+for (Record * record = batch->mRecordsHead;
+record < batch->mNextRecord;
+++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.
+uint32_t type = record->mType & 0xffffUL;
+uint32_t flags = record->mType >> 16;
+PR_snprintf(buf, kBufferSize,
+"{\"e\":\"%c\",\"t\":%llu,\"f\":%d,\"i\":\"%p\",\"n\":\"%s%s\"}%s\n",
+kTypeChars[type],
+static_cast<uint64_t>((record->mTime - mProfilerStart).ToMilliseconds()),
+flags,
+record->mItem,
+record->mText,
+record->mText2 ? record->mText2 : "",
+(record == batch->mNextRecord - 1) ? "" : ",");
+buffer.Append(buf);
+}
+buffer.Append(NS_LITERAL_CSTRING("]}\n"));
+RecordBatch * next = batch->mNextBatch;
+batch = next;
+}
+buffer.Append(NS_LITERAL_CSTRING("]}\n"));
+_retval.Assign(buffer);
+return NS_OK;
+}
+nsresult
+VisualEventTracerLog::WriteToProfilingFile()
+{
+const char* filename = PR_GetEnv("MOZ_TRACE_FILE");
+if (!filename) {
+return NS_OK;
+}
+PRFileDesc* fd = PR_Open(filename, PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
+			   0644);
+if (!fd) {
+return NS_ERROR_FILE_ACCESS_DENIED;
+}
+nsCString json;
+GetJSONString(json);
+int32_t bytesWritten = PR_Write(fd, json.get(), json.Length());
+PR_Close(fd);
+if (bytesWritten < json.Length()) {
+return NS_ERROR_UNEXPECTED;
+}
+return NS_OK;
+}
+NS_IMPL_ISUPPORTS(VisualEventTracer, nsIVisualEventTracer)
+NS_IMETHODIMP
+VisualEventTracer::Start(const uint32_t aMaxBacklogSeconds)
+{
+if (!gInitialized)
+return NS_ERROR_UNEXPECTED;
+if (gCapture) {
+NS_WARNING("VisualEventTracer has already been started");
+return NS_ERROR_ALREADY_INITIALIZED;
+}
+*gMaxBacklogTime = TimeDuration::FromMilliseconds(aMaxBacklogSeconds * 1000);
+*gProfilerStart = mozilla::TimeStamp::Now();
+{
+MonitorAutoLock mon(*gMonitor);
+RecordBatch::GCLog(*gProfilerStart);
+}
+gCapture = true;
+MOZ_EVENT_TRACER_MARK(this, "trace::start");
+return NS_OK;
+}
+NS_IMETHODIMP
+VisualEventTracer::Stop()
+{
+if (!gInitialized)
+return NS_ERROR_UNEXPECTED;
+if (!gCapture) {
+NS_WARNING("VisualEventTracer is not runing");
+return NS_ERROR_NOT_INITIALIZED;
+}
+MOZ_EVENT_TRACER_MARK(this, "trace::stop");
+gCapture = false;
+nsresult rv = NS_OK;
+if (PR_GetEnv("MOZ_TRACE_FILE")) {
+nsCOMPtr<nsIVisualEventTracerLog> tracelog;
+rv = Snapshot(getter_AddRefs(tracelog));
+if (NS_SUCCEEDED(rv)) {
+rv = tracelog->WriteToProfilingFile();
+}
+}
+return rv;
+}
+NS_IMETHODIMP
+VisualEventTracer::Snapshot(nsIVisualEventTracerLog ** _result)
+{
+if (!gInitialized)
+return NS_ERROR_UNEXPECTED;
+RecordBatch * batch = RecordBatch::CloneLog();
+nsRefPtr<VisualEventTracerLog> log = new VisualEventTracerLog(batch);
+log.forget(_result);
+return NS_OK;
+}
+#endif
+} // eventtracer
+} // mozilla

The Tor Browser / file comparison

comparison: xpcom/base/VisualEventTracer.cpp

xpcom/base/VisualEventTracer.cpp