summaryrefslogtreecommitdiffstats
path: root/js/src/vm/TraceLogging.cpp
diff options
context:
space:
mode:
Diffstat (limited to '')
-rw-r--r--js/src/vm/TraceLogging.cpp1844
1 files changed, 1844 insertions, 0 deletions
diff --git a/js/src/vm/TraceLogging.cpp b/js/src/vm/TraceLogging.cpp
new file mode 100644
index 0000000000..52342de443
--- /dev/null
+++ b/js/src/vm/TraceLogging.cpp
@@ -0,0 +1,1844 @@
+/* -*- 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 "vm/TraceLogging.h"
+
+#include "mozilla/EndianUtils.h"
+#include "mozilla/MemoryReporting.h"
+
+#include <algorithm>
+#include <string.h>
+#include <utility>
+
+#include "jit/BaselineJIT.h"
+#include "jit/CompileWrappers.h"
+#include "jit/JitSpewer.h"
+#include "js/friend/ErrorMessages.h" // js::GetErrorMessage, JSMSG_*
+#include "js/Printf.h"
+#include "js/TraceLoggerAPI.h"
+#include "threading/LockGuard.h"
+#include "util/Text.h"
+#include "vm/Activation.h" // js::ActivationIterator
+#include "vm/FrameIter.h" // js::JitFrameIter
+#include "vm/JSContext.h"
+#include "vm/JSScript.h"
+#include "vm/Runtime.h"
+#include "vm/Time.h"
+#include "vm/TraceLoggingGraph.h"
+
+using namespace js;
+
+static TraceLoggerThreadState* traceLoggerState = nullptr;
+
+static bool getTraceLoggerSupported() {
+ char* str = getenv("JS_TRACE_LOGGING");
+
+ if (!str) {
+ // Default to unsupported.
+ return false;
+ }
+
+ if (strcmp(str, "false") == 0 || strcmp(str, "no") == 0 ||
+ strcmp(str, "0") == 0) {
+ return false;
+ }
+
+ if (strcmp(str, "true") == 0 || strcmp(str, "yes") == 0 ||
+ strcmp(str, "1") == 0) {
+ fprintf(stderr, "Warning: TraceLogger disabled temporarily, bug 1565788\n");
+ return false;
+ }
+
+ fprintf(stderr, "Warning: I didn't understand JS_TRACE_LOGGING=\"%s\"\n",
+ str);
+ return false;
+}
+
+size_t js::SizeOfTraceLogState(mozilla::MallocSizeOf mallocSizeOf) {
+ return traceLoggerState ? traceLoggerState->sizeOfIncludingThis(mallocSizeOf)
+ : 0;
+}
+
+void js::ResetTraceLogger() {
+ if (!traceLoggerState) {
+ return;
+ }
+
+ traceLoggerState->clear();
+}
+
+void js::DestroyTraceLoggerThreadState() {
+ if (traceLoggerState) {
+ js_delete(traceLoggerState);
+ traceLoggerState = nullptr;
+ }
+}
+
+#ifdef DEBUG
+void js::AssertCurrentThreadOwnsTraceLoggerThreadStateLock() {
+ if (traceLoggerState) {
+ traceLoggerState->lock.assertOwnedByCurrentThread();
+ }
+}
+#endif
+
+void js::DestroyTraceLogger(TraceLoggerThread* logger) {
+ MOZ_ASSERT(traceLoggerState);
+ traceLoggerState->destroyLogger(logger);
+}
+
+bool TraceLoggerThread::init() {
+ if (!events_.init()) {
+ return false;
+ }
+
+ // Minimum amount of capacity needed for operation to allow flushing.
+ // Flushing requires space for the actual event and two spaces to log the
+ // start and stop of flushing.
+ if (!events_.ensureSpaceBeforeAdd(3)) {
+ return false;
+ }
+
+ char* buffer = js_pod_malloc<char>(32);
+ js::ThisThread::GetName(buffer, 32);
+ threadName_.reset(buffer);
+
+ return true;
+}
+
+void TraceLoggerThread::initGraph() {
+ // Create a graph. I don't like this is called reset, but it locks the
+ // graph into the UniquePtr. So it gets deleted when TraceLoggerThread
+ // is destructed.
+ graph_.reset(js_new<TraceLoggerGraph>());
+ if (!graph_.get()) {
+ return;
+ }
+
+ MOZ_ASSERT(traceLoggerState);
+ bool graphFile = traceLoggerState->isGraphFileEnabled();
+ double delta =
+ traceLoggerState->getTimeStampOffset(mozilla::TimeStamp::NowUnfuzzed());
+ uint64_t start = static_cast<uint64_t>(delta);
+ if (!graph_->init(start, graphFile)) {
+ graph_ = nullptr;
+ return;
+ }
+
+ if (graphFile) {
+ // Report the textIds to the graph.
+ for (uint32_t i = 0; i < TraceLogger_TreeItemEnd; i++) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ graph_->addTextId(i, TLTextIdString(id));
+ }
+ graph_->addTextId(TraceLogger_TreeItemEnd, "TraceLogger internal");
+ for (uint32_t i = TraceLogger_TreeItemEnd + 1; i < TraceLogger_Last; i++) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ graph_->addTextId(i, TLTextIdString(id));
+ }
+ }
+}
+
+void TraceLoggerThreadState::disableAllTextIds() {
+ for (uint32_t i = 1; i < TraceLogger_Last; i++) {
+ enabledTextIds[i] = false;
+ }
+}
+
+void TraceLoggerThreadState::enableTextIdsForProfiler() {
+ enableDefaultLogging();
+}
+
+void TraceLoggerThreadState::disableTextIdsForProfiler() {
+ disableAllTextIds();
+ // We have to keep the Baseline and IonMonkey id's alive because they control
+ // whether the jitted codegen has tracelogger start & stop events builtin.
+ // Otherwise, we end up in situations when some jitted code that was created
+ // before the profiler was even started ends up not starting and stoping any
+ // events. The TraceLogger_Engine stop events can accidentally stop the wrong
+ // event in this case, and then it's no longer possible to build a graph.
+ enabledTextIds[TraceLogger_Engine] = true;
+ enabledTextIds[TraceLogger_Interpreter] = true;
+ enabledTextIds[TraceLogger_Baseline] = true;
+ enabledTextIds[TraceLogger_IonMonkey] = true;
+}
+
+void TraceLoggerThreadState::enableDefaultLogging() {
+ enabledTextIds[TraceLogger_AnnotateScripts] = true;
+ enabledTextIds[TraceLogger_Bailout] = true;
+ enabledTextIds[TraceLogger_Baseline] = true;
+ enabledTextIds[TraceLogger_BaselineCompilation] = true;
+ enabledTextIds[TraceLogger_GC] = true;
+ enabledTextIds[TraceLogger_GCAllocation] = true;
+ enabledTextIds[TraceLogger_GCSweeping] = true;
+ enabledTextIds[TraceLogger_Interpreter] = true;
+ enabledTextIds[TraceLogger_IonAnalysis] = true;
+ enabledTextIds[TraceLogger_IonCompilation] = true;
+ enabledTextIds[TraceLogger_IonLinking] = true;
+ enabledTextIds[TraceLogger_IonMonkey] = true;
+ enabledTextIds[TraceLogger_MinorGC] = true;
+ enabledTextIds[TraceLogger_Frontend] = true;
+ enabledTextIds[TraceLogger_ParsingFull] = true;
+ enabledTextIds[TraceLogger_ParsingSyntax] = true;
+ enabledTextIds[TraceLogger_BytecodeEmission] = true;
+ enabledTextIds[TraceLogger_IrregexpCompile] = true;
+ enabledTextIds[TraceLogger_IrregexpExecute] = true;
+ enabledTextIds[TraceLogger_Scripts] = true;
+ enabledTextIds[TraceLogger_Engine] = true;
+ enabledTextIds[TraceLogger_WasmCompilation] = true;
+ enabledTextIds[TraceLogger_Invalidation] = true;
+}
+
+void TraceLoggerThreadState::enableIonLogging() {
+ enabledTextIds[TraceLogger_IonCompilation] = true;
+ enabledTextIds[TraceLogger_IonLinking] = true;
+ enabledTextIds[TraceLogger_PruneUnusedBranches] = true;
+ enabledTextIds[TraceLogger_FoldTests] = true;
+ enabledTextIds[TraceLogger_SplitCriticalEdges] = true;
+ enabledTextIds[TraceLogger_RenumberBlocks] = true;
+ enabledTextIds[TraceLogger_ScalarReplacement] = true;
+ enabledTextIds[TraceLogger_DominatorTree] = true;
+ enabledTextIds[TraceLogger_PhiAnalysis] = true;
+ enabledTextIds[TraceLogger_MakeLoopsContiguous] = true;
+ enabledTextIds[TraceLogger_ApplyTypes] = true;
+ enabledTextIds[TraceLogger_EagerSimdUnbox] = true;
+ enabledTextIds[TraceLogger_AliasAnalysis] = true;
+ enabledTextIds[TraceLogger_GVN] = true;
+ enabledTextIds[TraceLogger_LICM] = true;
+ enabledTextIds[TraceLogger_RangeAnalysis] = true;
+ enabledTextIds[TraceLogger_LoopUnrolling] = true;
+ enabledTextIds[TraceLogger_FoldLinearArithConstants] = true;
+ enabledTextIds[TraceLogger_EffectiveAddressAnalysis] = true;
+ enabledTextIds[TraceLogger_AlignmentMaskAnalysis] = true;
+ enabledTextIds[TraceLogger_EliminateDeadCode] = true;
+ enabledTextIds[TraceLogger_ReorderInstructions] = true;
+ enabledTextIds[TraceLogger_EdgeCaseAnalysis] = true;
+ enabledTextIds[TraceLogger_EliminateRedundantChecks] = true;
+ enabledTextIds[TraceLogger_AddKeepAliveInstructions] = true;
+ enabledTextIds[TraceLogger_GenerateLIR] = true;
+ enabledTextIds[TraceLogger_RegisterAllocation] = true;
+ enabledTextIds[TraceLogger_GenerateCode] = true;
+ enabledTextIds[TraceLogger_Scripts] = true;
+}
+
+void TraceLoggerThreadState::enableFrontendLogging() {
+ enabledTextIds[TraceLogger_Frontend] = true;
+ enabledTextIds[TraceLogger_ParsingFull] = true;
+ enabledTextIds[TraceLogger_ParsingSyntax] = true;
+ enabledTextIds[TraceLogger_BytecodeEmission] = true;
+ enabledTextIds[TraceLogger_BytecodeFoldConstants] = true;
+ enabledTextIds[TraceLogger_BytecodeNameFunctions] = true;
+}
+
+TraceLoggerThread::~TraceLoggerThread() {
+ if (graph_.get()) {
+ if (!failed_) {
+ graph_->log(events_, traceLoggerState->startTime);
+ }
+ graph_ = nullptr;
+ }
+}
+
+bool TraceLoggerThread::enable() {
+ if (enabled_ > 0) {
+ enabled_++;
+ return true;
+ }
+
+ if (failed_) {
+ return false;
+ }
+
+ enabled_ = 1;
+ logTimestamp(TraceLogger_Enable);
+
+ return true;
+}
+
+bool TraceLoggerThread::fail(JSContext* cx, const char* error) {
+ JS_ReportErrorNumberASCII(cx, GetErrorMessage, nullptr,
+ JSMSG_TRACELOGGER_ENABLE_FAIL, error);
+ failed_ = true;
+ enabled_ = 0;
+
+ return false;
+}
+
+void TraceLoggerThread::silentFail(const char* error) {
+ traceLoggerState->maybeSpewError(error);
+ failed_ = true;
+ enabled_ = 0;
+}
+
+size_t TraceLoggerThread::sizeOfExcludingThis(
+ mozilla::MallocSizeOf mallocSizeOf) const {
+ size_t size = 0;
+#ifdef DEBUG
+ size += graphStack_.sizeOfExcludingThis(mallocSizeOf);
+#endif
+ size += events_.sizeOfExcludingThis(mallocSizeOf);
+ if (graph_.get()) {
+ size += graph_->sizeOfIncludingThis(mallocSizeOf);
+ }
+ return size;
+}
+
+size_t TraceLoggerThread::sizeOfIncludingThis(
+ mozilla::MallocSizeOf mallocSizeOf) const {
+ return mallocSizeOf(this) + sizeOfExcludingThis(mallocSizeOf);
+}
+
+bool TraceLoggerThread::enable(JSContext* cx) {
+ using namespace js::jit;
+
+ if (!enable()) {
+ return fail(cx, "internal error");
+ }
+
+ if (enabled_ == 1) {
+ // Get the top Activation to log the top script/pc (No inlined frames).
+ ActivationIterator iter(cx);
+ Activation* act = iter.activation();
+
+ if (!act) {
+ return fail(cx, "internal error");
+ }
+
+ JSScript* script = nullptr;
+ int32_t engine = 0;
+
+ if (act->isJit()) {
+ JitFrameIter frame(iter->asJit());
+
+ while (!frame.done()) {
+ if (frame.isWasm()) {
+ JS_ReportErrorNumberASCII(cx, GetErrorMessage, nullptr,
+ JSMSG_TRACELOGGER_ENABLE_FAIL,
+ "not yet supported in wasm code");
+ return false;
+ }
+ if (frame.asJSJit().isScripted()) {
+ break;
+ }
+ ++frame;
+ }
+
+ MOZ_ASSERT(!frame.done());
+
+ const JSJitFrameIter& jitFrame = frame.asJSJit();
+ MOZ_ASSERT(jitFrame.isIonJS() || jitFrame.isBaselineJS());
+
+ script = jitFrame.script();
+ engine =
+ jitFrame.isIonJS() ? TraceLogger_IonMonkey : TraceLogger_Baseline;
+ } else {
+ MOZ_ASSERT(act->isInterpreter());
+ InterpreterFrame* fp = act->asInterpreter()->current();
+ MOZ_ASSERT(!fp->runningInJit());
+
+ script = fp->script();
+ engine = TraceLogger_Interpreter;
+ }
+ if (script->compartment() != cx->compartment()) {
+ return fail(cx, "compartment mismatch");
+ }
+
+ TraceLoggerEvent event(TraceLogger_Scripts, script);
+ startEvent(event);
+ startEvent(engine);
+ }
+
+ return true;
+}
+
+bool TraceLoggerThread::disable(bool force, const char* error) {
+ if (failed_) {
+ MOZ_ASSERT(enabled_ == 0);
+ return false;
+ }
+
+ if (enabled_ == 0) {
+ return true;
+ }
+
+ if (enabled_ > 1 && !force) {
+ enabled_--;
+ return true;
+ }
+
+ if (force) {
+ traceLoggerState->maybeSpewError(error);
+ }
+
+ logTimestamp(TraceLogger_Disable);
+ enabled_ = 0;
+
+ return true;
+}
+
+const char* TraceLoggerThread::maybeEventText(uint32_t id) {
+ if (TLTextIdIsEnumEvent(id)) {
+ return TLTextIdString(static_cast<TraceLoggerTextId>(id));
+ }
+ return traceLoggerState->maybeEventText(id);
+}
+
+TraceLoggerEventPayload* TraceLoggerThreadState::getPayload(uint32_t id) {
+ if (TLTextIdIsEnumEvent(id)) {
+ return nullptr;
+ }
+
+ TextIdToPayloadMap::Ptr p = textIdPayloads.lookup(id);
+ if (!p) {
+ return nullptr;
+ }
+
+ p->value()->use();
+ return p->value();
+}
+
+const char* TraceLoggerThreadState::maybeEventText(uint32_t id) {
+ LockGuard<Mutex> guard(lock);
+
+ TextIdToPayloadMap::Ptr p = textIdPayloads.lookup(id);
+ if (!p) {
+ return nullptr;
+ }
+
+ uint32_t dictId = p->value()->dictionaryId();
+ MOZ_ASSERT(dictId < nextDictionaryId);
+ return dictionaryData[dictId].get();
+}
+
+const char* TraceLoggerThreadState::maybeEventText(TraceLoggerEventPayload* p) {
+ LockGuard<Mutex> guard(lock);
+ if (!p) {
+ return nullptr;
+ }
+
+ uint32_t dictId = p->dictionaryId();
+ MOZ_ASSERT(dictId < nextDictionaryId);
+ return dictionaryData[dictId].get();
+}
+
+size_t TraceLoggerThreadState::sizeOfExcludingThis(
+ mozilla::MallocSizeOf mallocSizeOf) {
+ LockGuard<Mutex> guard(lock);
+
+ // Do not count threadLoggers since they are counted by
+ // JSContext::traceLogger.
+
+ size_t size = 0;
+ size += dictionaryData.sizeOfExcludingThis(mallocSizeOf);
+ size += payloadDictionary.shallowSizeOfExcludingThis(mallocSizeOf);
+ size += textIdPayloads.shallowSizeOfExcludingThis(mallocSizeOf);
+ for (TextIdToPayloadMap::Range r = textIdPayloads.all(); !r.empty();
+ r.popFront()) {
+ r.front().value()->sizeOfIncludingThis(mallocSizeOf);
+ }
+
+ return size;
+}
+
+TraceLoggerEventPayload* TraceLoggerThreadState::getOrCreateEventPayload(
+ const char* text) {
+ LockGuard<Mutex> guard(lock);
+
+ uint32_t dictId = nextDictionaryId;
+
+ StringHashToDictionaryMap::AddPtr dictp =
+ payloadDictionary.lookupForAdd(text);
+ if (dictp) {
+ dictId = dictp->value();
+ MOZ_ASSERT(dictId < nextDictionaryId); // Sanity check.
+ } else {
+ UniqueChars str = DuplicateString(text);
+ if (!str) {
+ return nullptr;
+ }
+ if (!payloadDictionary.add(dictp, str.get(), nextDictionaryId)) {
+ return nullptr;
+ }
+ if (!dictionaryData.append(std::move(str))) {
+ return nullptr;
+ }
+
+ nextDictionaryId++;
+ }
+
+ // Look for a free entry, as some textId's may
+ // already be taken from previous profiling sessions.
+ while (textIdPayloads.has(nextTextId)) {
+ nextTextId++;
+ }
+
+ auto* payload = js_new<TraceLoggerEventPayload>(nextTextId, dictId);
+ if (!payload) {
+ return nullptr;
+ }
+
+ if (!textIdPayloads.putNew(nextTextId, payload)) {
+ js_delete(payload);
+ return nullptr;
+ }
+
+ payload->use();
+
+ nextTextId++;
+
+ return payload;
+}
+
+TraceLoggerEventPayload* TraceLoggerThreadState::getOrCreateEventPayload(
+ const char* filename, uint32_t lineno, uint32_t colno) {
+ if (!filename) {
+ filename = "<unknown>";
+ }
+
+ TraceLoggerEventPayload* payload = getOrCreateEventPayload(filename);
+ if (!payload) {
+ return nullptr;
+ }
+
+ payload->setLine(lineno);
+ payload->setColumn(colno);
+
+ return payload;
+}
+
+TraceLoggerEventPayload* TraceLoggerThreadState::getOrCreateEventPayload(
+ JSScript* script) {
+ return getOrCreateEventPayload(script->filename(), script->lineno(),
+ script->column());
+}
+
+void TraceLoggerThreadState::purgeUnusedPayloads() {
+ // Care needs to be taken to maintain a coherent state in this function,
+ // as payloads can have their use count change at any time from non-zero to
+ // zero (but not the other way around; see TraceLoggerEventPayload::use()).
+ LockGuard<Mutex> guard(lock);
+
+ // Free all other payloads that have no uses anymore.
+ for (TextIdToPayloadMap::Enum e(textIdPayloads); !e.empty(); e.popFront()) {
+ if (e.front().value()->uses() == 0) {
+ uint32_t dictId = e.front().value()->dictionaryId();
+ dictionaryData.erase(dictionaryData.begin() + dictId);
+ js_delete(e.front().value());
+ e.removeFront();
+ }
+ }
+}
+
+void TraceLoggerThread::startEvent(TraceLoggerTextId id) {
+ startEvent(uint32_t(id));
+}
+
+void TraceLoggerThread::startEvent(const TraceLoggerEvent& event) {
+ if (!event.hasTextId()) {
+ if (!enabled()) {
+ return;
+ }
+ startEvent(TraceLogger_Error);
+ disable(/* force = */ true,
+ "TraceLogger encountered an empty event. "
+ "Potentially due to OOM during creation of "
+ "this event. Disabling TraceLogger.");
+ return;
+ }
+ startEvent(event.textId());
+}
+
+void TraceLoggerThread::startEvent(uint32_t id) {
+ if (!jit::JitOptions.enableTraceLogger) {
+ return;
+ }
+
+ MOZ_ASSERT(TLTextIdIsTreeEvent(id) || id == TraceLogger_Error);
+ MOZ_ASSERT(traceLoggerState);
+ if (!traceLoggerState->isTextIdEnabled(id)) {
+ return;
+ }
+
+#ifdef DEBUG
+ if (enabled_ > 0) {
+ AutoEnterOOMUnsafeRegion oomUnsafe;
+ if (!graphStack_.append(id)) {
+ oomUnsafe.crash("Could not add item to debug stack.");
+ }
+ }
+#endif
+
+ if (graph_.get() && traceLoggerState->isGraphFileEnabled()) {
+ // Flush each textId to disk. textId values up to TraceLogger_Last are
+ // statically defined and each one has an associated constant event string
+ // defined by TLTextIdString(). For any events with textId >=
+ // TraceLogger_Last the payload associated with that textId must first be
+ // found and then maybeEventText() will find the event string form the
+ // dictionary.
+ for (uint32_t otherId = graph_->nextTextId(); otherId <= id; otherId++) {
+ if (TLTextIdIsEnumEvent(id)) {
+ const char* text = TLTextIdString(static_cast<TraceLoggerTextId>(id));
+ graph_->addTextId(otherId, text);
+ } else {
+ TraceLoggerEventPayload* p = traceLoggerState->getPayload(id);
+ if (p) {
+ const char* filename = traceLoggerState->maybeEventText(p);
+ mozilla::Maybe<uint32_t> line = p->line();
+ mozilla::Maybe<uint32_t> column = p->column();
+ graph_->addTextId(otherId, filename, line, column);
+ p->release();
+ }
+ }
+ }
+ }
+
+ log(id);
+}
+
+void TraceLoggerThread::stopEvent(TraceLoggerTextId id) {
+ stopEvent(uint32_t(id));
+}
+
+void TraceLoggerThread::stopEvent(const TraceLoggerEvent& event) {
+ if (!event.hasTextId()) {
+ stopEvent(TraceLogger_Error);
+ return;
+ }
+ stopEvent(event.textId());
+}
+
+void TraceLoggerThread::stopEvent(uint32_t id) {
+ if (!jit::JitOptions.enableTraceLogger) {
+ return;
+ }
+
+ MOZ_ASSERT(TLTextIdIsTreeEvent(id) || id == TraceLogger_Error);
+ MOZ_ASSERT(traceLoggerState);
+ if (!traceLoggerState->isTextIdEnabled(id)) {
+ return;
+ }
+
+#ifdef DEBUG
+ if (!graphStack_.empty()) {
+ uint32_t prev = graphStack_.popCopy();
+ if (id == TraceLogger_Error || prev == TraceLogger_Error) {
+ // When encountering an Error id the stack will most likely not be correct
+ // anymore. Ignore this.
+ } else if (id == TraceLogger_Engine) {
+ MOZ_ASSERT(prev == TraceLogger_IonMonkey ||
+ prev == TraceLogger_Baseline ||
+ prev == TraceLogger_Interpreter);
+ } else if (id == TraceLogger_Scripts) {
+ MOZ_ASSERT(TLTextIdIsScriptEvent(prev));
+ } else if (TLTextIdIsScriptEvent(id)) {
+ MOZ_ASSERT(TLTextIdIsScriptEvent(prev));
+ if (prev != id) {
+ // Ignore if the text has been flushed already.
+ MOZ_ASSERT_IF(maybeEventText(prev),
+ strcmp(maybeEventText(id), maybeEventText(prev)) == 0);
+ }
+ } else {
+ MOZ_ASSERT(id == prev);
+ }
+ }
+#endif
+
+ log(TraceLogger_Stop);
+}
+
+JS::AutoTraceLoggerLockGuard::AutoTraceLoggerLockGuard() {
+ traceLoggerState->lock.lock();
+}
+
+JS::AutoTraceLoggerLockGuard::~AutoTraceLoggerLockGuard() {
+ traceLoggerState->lock.unlock();
+}
+
+size_t JS::TraceLoggerDictionaryImpl::NextChunk(JSContext* cx,
+ size_t* dataIndex,
+ char buffer[],
+ size_t bufferSize) {
+ MOZ_ASSERT(dataIndex != nullptr);
+ if (!traceLoggerState || bufferSize == 0 || !buffer ||
+ !jit::JitOptions.enableTraceLogger) {
+ return 0;
+ }
+
+ size_t bufferIndex = 0;
+
+ const char* eventString = nullptr;
+ if (TLTextIdIsEnumEvent(*dataIndex)) {
+ eventString = TLTextIdString(static_cast<TraceLoggerTextId>(*dataIndex));
+ } else {
+ uint32_t dictId = *dataIndex - TraceLogger_Last;
+ if (dictId < traceLoggerState->dictionaryData.length()) {
+ eventString = traceLoggerState->dictionaryData[dictId].get();
+ MOZ_ASSERT(eventString);
+ }
+ }
+
+ if (eventString) {
+ size_t length = strlen(eventString);
+ if (length < bufferSize - 1) {
+ memcpy(buffer, eventString, length);
+ buffer[length] = '\0';
+ bufferIndex = length;
+ } else {
+ memcpy(buffer, eventString, bufferSize);
+ buffer[bufferSize - 1] = '\0';
+ bufferIndex = bufferSize - 1;
+ }
+ }
+
+ (*dataIndex)++;
+ return bufferIndex;
+}
+
+size_t JS::TraceLoggerIdImpl::NextChunk(JSContext* cx, size_t* dataIndex,
+ uint32_t buffer[], size_t bufferSize) {
+ MOZ_ASSERT(dataIndex != nullptr);
+ if (!cx || !cx->traceLogger) {
+ return 0;
+ }
+
+ if (bufferSize == 0 || !buffer || !jit::JitOptions.enableTraceLogger) {
+ return 0;
+ }
+
+ size_t bufferIndex = 0;
+ ContinuousSpace<EventEntry>& events = cx->traceLogger->events_;
+
+ for (; *dataIndex < events.size(); (*dataIndex)++) {
+ if (TLTextIdIsInternalEvent(events[*dataIndex].textId)) {
+ continue;
+ }
+
+ if (TLTextIdIsScriptEvent(events[*dataIndex].textId)) {
+ TraceLoggerEventPayload* payload =
+ traceLoggerState->getPayload(events[*dataIndex].textId);
+ MOZ_ASSERT(payload);
+ if (!payload) {
+ return 0;
+ }
+ // Write the index of this event into the jsTracerDictionary array
+ // property
+ uint32_t dictId = TraceLogger_Last + payload->dictionaryId();
+ buffer[bufferIndex++] = dictId;
+ payload->release();
+ } else {
+ buffer[bufferIndex++] = events[*dataIndex].textId;
+ }
+
+ if (bufferIndex == bufferSize) {
+ break;
+ }
+ }
+
+ return bufferIndex;
+}
+
+size_t JS::TraceLoggerLineNoImpl::NextChunk(JSContext* cx, size_t* dataIndex,
+ int32_t buffer[],
+ size_t bufferSize) {
+ MOZ_ASSERT(dataIndex != nullptr);
+ if (!cx || !cx->traceLogger) {
+ return 0;
+ }
+
+ if (bufferSize == 0 || !buffer || !jit::JitOptions.enableTraceLogger) {
+ return 0;
+ }
+
+ size_t bufferIndex = 0;
+ ContinuousSpace<EventEntry>& events = cx->traceLogger->events_;
+
+ for (; *dataIndex < events.size(); (*dataIndex)++) {
+ if (TLTextIdIsInternalEvent(events[*dataIndex].textId)) {
+ continue;
+ }
+
+ if (TLTextIdIsScriptEvent(events[*dataIndex].textId)) {
+ TraceLoggerEventPayload* payload =
+ traceLoggerState->getPayload(events[*dataIndex].textId);
+ MOZ_ASSERT(payload);
+ if (!payload) {
+ return 0;
+ }
+ mozilla::Maybe<uint32_t> line = payload->line();
+ payload->release();
+ if (line) {
+ buffer[bufferIndex++] = *line;
+ } else {
+ buffer[bufferIndex++] = -1;
+ }
+ } else {
+ buffer[bufferIndex++] = -1;
+ }
+ if (bufferIndex == bufferSize) {
+ break;
+ }
+ }
+
+ return bufferIndex;
+}
+
+size_t JS::TraceLoggerColNoImpl::NextChunk(JSContext* cx, size_t* dataIndex,
+ int32_t buffer[],
+ size_t bufferSize) {
+ MOZ_ASSERT(dataIndex != nullptr);
+ if (!cx || !cx->traceLogger) {
+ return 0;
+ }
+
+ if (bufferSize == 0 || !buffer || !jit::JitOptions.enableTraceLogger) {
+ return 0;
+ }
+
+ size_t bufferIndex = 0;
+ ContinuousSpace<EventEntry>& events = cx->traceLogger->events_;
+
+ for (; *dataIndex < events.size(); (*dataIndex)++) {
+ if (TLTextIdIsInternalEvent(events[*dataIndex].textId)) {
+ continue;
+ }
+
+ if (TLTextIdIsScriptEvent(events[*dataIndex].textId)) {
+ TraceLoggerEventPayload* payload =
+ traceLoggerState->getPayload(events[*dataIndex].textId);
+ MOZ_ASSERT(payload);
+ if (!payload) {
+ return 0;
+ }
+ mozilla::Maybe<uint32_t> column = payload->column();
+ payload->release();
+ if (column) {
+ buffer[bufferIndex++] = *column;
+ } else {
+ buffer[bufferIndex++] = -1;
+ }
+ } else {
+ buffer[bufferIndex++] = -1;
+ }
+ if (bufferIndex == bufferSize) {
+ break;
+ }
+ }
+
+ return bufferIndex;
+}
+
+size_t JS::TraceLoggerTimeStampImpl::NextChunk(JSContext* cx, size_t* dataIndex,
+ mozilla::TimeStamp buffer[],
+ size_t bufferSize) {
+ MOZ_ASSERT(dataIndex != nullptr);
+ if (!cx || !cx->traceLogger) {
+ return 0;
+ }
+
+ if (bufferSize == 0 || !buffer || !jit::JitOptions.enableTraceLogger) {
+ return 0;
+ }
+
+ size_t bufferIndex = 0;
+ ContinuousSpace<EventEntry>& events = cx->traceLogger->events_;
+
+ for (; *dataIndex < events.size(); (*dataIndex)++) {
+ if (TLTextIdIsInternalEvent(events[*dataIndex].textId)) {
+ continue;
+ }
+ buffer[bufferIndex++] = events[*dataIndex].time;
+ if (bufferIndex == bufferSize) {
+ break;
+ }
+ }
+
+ return bufferIndex;
+}
+
+size_t JS::TraceLoggerDurationImpl::NextChunk(JSContext* cx, size_t* dataIndex,
+ double buffer[],
+ size_t bufferSize) {
+ MOZ_ASSERT(dataIndex != nullptr);
+ if (!cx || !cx->traceLogger) {
+ return 0;
+ }
+
+ if (bufferSize == 0 || !buffer || !jit::JitOptions.enableTraceLogger) {
+ return 0;
+ }
+
+ ContinuousSpace<EventEntry>& events = cx->traceLogger->events_;
+ Vector<size_t, 0, js::SystemAllocPolicy> eventStack;
+ using EventDurationMap =
+ HashMap<size_t, double, DefaultHasher<size_t>, SystemAllocPolicy>;
+ EventDurationMap eventMap;
+
+ size_t bufferIndex = 0;
+ for (; *dataIndex < events.size(); (*dataIndex)++) {
+ if (TLTextIdIsInternalEvent(events[*dataIndex].textId)) {
+ continue;
+ }
+ double duration = 0;
+ if (TLTextIdIsLogEvent(events[*dataIndex].textId)) {
+ // log events are snapshot events with no start & stop
+ duration = -1;
+ } else if (EventDurationMap::Ptr p = eventMap.lookup(*dataIndex)) {
+ // value has already been cached
+ duration = p->value();
+ } else {
+ MOZ_ASSERT(eventStack.empty());
+ if (!eventStack.append(*dataIndex)) {
+ return 0;
+ }
+
+ // Search through the events array to find the matching stop event in
+ // order to calculate the duration time. Cache all other durations we
+ // calculate in the meantime.
+ for (size_t j = *dataIndex + 1; j < events.size(); j++) {
+ uint32_t id = events[j].textId;
+ if (id == TraceLogger_Stop) {
+ uint32_t prev = eventStack.popCopy();
+ double delta = (events[j].time - events[prev].time).ToMicroseconds();
+ if (prev == *dataIndex) {
+ MOZ_ASSERT(eventStack.empty());
+ duration = delta;
+ break;
+ }
+
+ if (!eventMap.putNew(prev, delta)) {
+ return 0;
+ }
+
+ } else if (TLTextIdIsTreeEvent(id)) {
+ if (!eventStack.append(j)) {
+ return 0;
+ }
+ }
+
+ // If we reach the end of the list, use the last event as the end
+ // event for all events remaining on the stack.
+ if (j == events.size() - 1) {
+ while (!eventStack.empty()) {
+ uint32_t prev = eventStack.popCopy();
+ double delta =
+ (events[j].time - events[prev].time).ToMicroseconds();
+ if (prev == *dataIndex) {
+ MOZ_ASSERT(eventStack.empty());
+ duration = delta;
+ } else {
+ if (!eventMap.putNew(prev, delta)) {
+ return 0;
+ }
+ }
+ }
+ }
+ }
+ }
+
+ buffer[bufferIndex++] = duration;
+ if (bufferIndex == bufferSize) {
+ break;
+ }
+ }
+
+ return bufferIndex;
+}
+
+void TraceLoggerThread::logTimestamp(TraceLoggerTextId id) {
+ logTimestamp(uint32_t(id));
+}
+
+void TraceLoggerThread::logTimestamp(uint32_t id) {
+ MOZ_ASSERT(id > TraceLogger_TreeItemEnd && id < TraceLogger_Last);
+ log(id);
+}
+
+void TraceLoggerThread::log(uint32_t id) {
+ if (enabled_ == 0) {
+ return;
+ }
+
+#ifdef DEBUG
+ if (id == TraceLogger_Disable) {
+ graphStack_.clear();
+ }
+#endif
+
+ MOZ_ASSERT(traceLoggerState);
+
+ // We request for 3 items to add, since if we don't have enough room
+ // we record the time it took to make more space. To log this information
+ // we need 2 extra free entries.
+ if (!events_.hasSpaceForAdd(3)) {
+ mozilla::TimeStamp start = mozilla::TimeStamp::NowUnfuzzed();
+
+ if (!events_.ensureSpaceBeforeAdd(3)) {
+ if (graph_.get()) {
+ graph_->log(events_, traceLoggerState->startTime);
+ }
+
+ // The data structures are full, and the graph file is not enabled
+ // so we cannot flush to disk. Trace logging should stop here.
+ if (!traceLoggerState->isGraphFileEnabled()) {
+ enabled_ = 0;
+ return;
+ }
+
+ iteration_++;
+ events_.clear();
+
+ // Periodically remove unused payloads from the global logger state.
+ traceLoggerState->purgeUnusedPayloads();
+ }
+
+ // Log the time it took to flush the events_ as being from the
+ // Tracelogger.
+ if (graph_.get()) {
+ MOZ_ASSERT(events_.hasSpaceForAdd(2));
+ EventEntry& entryStart = events_.pushUninitialized();
+ entryStart.time = start;
+ entryStart.textId = TraceLogger_Internal;
+
+ EventEntry& entryStop = events_.pushUninitialized();
+ entryStop.time = mozilla::TimeStamp::NowUnfuzzed();
+ entryStop.textId = TraceLogger_Stop;
+ }
+ }
+
+ mozilla::TimeStamp time = mozilla::TimeStamp::NowUnfuzzed();
+
+ EventEntry& entry = events_.pushUninitialized();
+ entry.time = time;
+ entry.textId = id;
+}
+
+bool TraceLoggerThreadState::remapDictionaryEntries(
+ mozilla::Vector<UniqueChars, 0, SystemAllocPolicy>* newDictionary,
+ uint32_t* newNextDictionaryId) {
+ MOZ_ASSERT(newNextDictionaryId != nullptr && newDictionary != nullptr);
+
+ typedef HashMap<uint32_t, uint32_t, DefaultHasher<uint32_t>,
+ SystemAllocPolicy>
+ DictionaryMap;
+ DictionaryMap dictionaryMap;
+
+ // Clear all payloads that are not currently used. There may be some events
+ // that still hold a pointer to a payload. Restarting the profiler may reuse
+ // the exact same event as a previous session if it's still alive so we need
+ // to maintain it's existence.
+ for (TextIdToPayloadMap::Enum e(textIdPayloads); !e.empty(); e.popFront()) {
+ if (e.front().value()->uses() == 0) {
+ js_delete(e.front().value());
+ e.removeFront();
+ } else {
+ TraceLoggerEventPayload* payload = e.front().value();
+ uint32_t dictId = payload->dictionaryId();
+
+ if (dictionaryMap.has(dictId)) {
+ DictionaryMap::Ptr mapPointer = dictionaryMap.lookup(dictId);
+ MOZ_ASSERT(mapPointer);
+ payload->setDictionaryId(mapPointer->value());
+ } else {
+ if (!newDictionary->append(std::move(dictionaryData[dictId]))) {
+ return false;
+ }
+ payload->setDictionaryId(*newNextDictionaryId);
+
+ if (!dictionaryMap.putNew(dictId, *newNextDictionaryId)) {
+ return false;
+ }
+
+ (*newNextDictionaryId)++;
+ }
+ }
+ }
+
+ return true;
+}
+
+void TraceLoggerThreadState::clear() {
+ LockGuard<Mutex> guard(lock);
+
+ uint32_t newNextDictionaryId = 0;
+ mozilla::Vector<UniqueChars, 0, SystemAllocPolicy> newDictionary;
+ if (remapDictionaryEntries(&newDictionary, &newNextDictionaryId)) {
+ // Clear and free any data used for the string dictionary.
+ for (auto range = dictionaryData.all(); !range.empty(); range.popFront()) {
+ range.front().reset();
+ }
+ dictionaryData.clearAndFree();
+ dictionaryData = std::move(newDictionary);
+
+ payloadDictionary.clearAndCompact();
+
+ nextTextId = TraceLogger_Last;
+ nextDictionaryId = newNextDictionaryId;
+ }
+
+ for (TraceLoggerThread* logger : threadLoggers) {
+ logger->clear();
+ }
+}
+
+void TraceLoggerThread::clear() {
+ if (graph_.get()) {
+ graph_.reset();
+ }
+
+ graph_ = nullptr;
+
+#ifdef DEBUG
+ graphStack_.clear();
+#endif
+
+ if (!events_.reset()) {
+ silentFail("Cannot reset event buffer.");
+ }
+}
+
+TraceLoggerThreadState::~TraceLoggerThreadState() {
+ while (TraceLoggerThread* logger = threadLoggers.popFirst()) {
+ js_delete(logger);
+ }
+
+ threadLoggers.clear();
+
+ for (TextIdToPayloadMap::Range r = textIdPayloads.all(); !r.empty();
+ r.popFront()) {
+ js_delete(r.front().value());
+ }
+
+#ifdef DEBUG
+ initialized = false;
+#endif
+}
+
+bool TraceLoggerThreadState::init() {
+ const char* env = getenv("TLLOG");
+ if (env) {
+ if (strstr(env, "help")) {
+ fflush(nullptr);
+ printf(
+ "\n"
+ "usage: TLLOG=option,option,option,... where options can be:\n"
+ "\n"
+ "Collections:\n"
+ " Default Output all default. It includes:\n"
+ " AnnotateScripts, Bailout, Baseline, "
+ "BaselineCompilation, GC,\n"
+ " GCAllocation, GCSweeping, Interpreter, "
+ "IonAnalysis, IonCompilation,\n"
+ " IonLinking, IonMonkey, MinorGC, Frontend, "
+ "ParsingFull,\n"
+ " ParsingSyntax, BytecodeEmission, IrregexpCompile, "
+ "IrregexpExecute,\n"
+ " Scripts, Engine, WasmCompilation\n"
+ "\n"
+ " IonCompiler Output all information about compilation. It "
+ "includes:\n"
+ " IonCompilation, IonLinking, PruneUnusedBranches, "
+ "FoldTests,\n"
+ " SplitCriticalEdges, RenumberBlocks, "
+ "ScalarReplacement,\n"
+ " DominatorTree, PhiAnalysis, MakeLoopsContiguous, "
+ "ApplyTypes,\n"
+ " EagerSimdUnbox, AliasAnalysis, GVN, LICM, "
+ "RangeAnalysis,\n"
+ " LoopUnrolling, FoldLinearArithConstants, "
+ "EffectiveAddressAnalysis,\n"
+ " AlignmentMaskAnalysis, EliminateDeadCode, "
+ "ReorderInstructions,\n"
+ " EdgeCaseAnalysis, EliminateRedundantChecks,\n"
+ " AddKeepAliveInstructions, GenerateLIR, "
+ "RegisterAllocation,\n"
+ " GenerateCode, Scripts\n"
+ "\n"
+ " VMSpecific Output the specific name of the VM call\n"
+ "\n"
+ " Frontend Output all information about frontend compilation. "
+ "It includes:\n"
+ " Frontend, ParsingFull, ParsingSyntax, Tokenizing,\n"
+ " BytecodeEmission, BytecodeFoldConstants, "
+ "BytecodeNameFunctions\n"
+ "Specific log items:\n");
+ for (uint32_t i = 1; i < TraceLogger_Last; i++) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ if (!TLTextIdIsTogglable(id)) {
+ continue;
+ }
+ printf(" %s\n", TLTextIdString(id));
+ }
+ printf("\n");
+ exit(0);
+ /*NOTREACHED*/
+ }
+
+ for (uint32_t i = 1; i < TraceLogger_Last; i++) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ if (TLTextIdIsTogglable(id)) {
+ enabledTextIds[i] = ContainsFlag(env, TLTextIdString(id));
+ } else {
+ enabledTextIds[i] = true;
+ }
+ }
+
+ if (ContainsFlag(env, "Default")) {
+ enableDefaultLogging();
+ }
+
+ if (ContainsFlag(env, "IonCompiler")) {
+ enableIonLogging();
+ }
+
+ if (ContainsFlag(env, "Frontend")) {
+ enableFrontendLogging();
+ }
+
+#ifdef DEBUG
+ enabledTextIds[TraceLogger_Error] = true;
+#endif
+
+ } else {
+ // Most of the textId's will be enabled through JS::StartTraceLogger when
+ // the gecko profiler is started.
+ disableTextIdsForProfiler();
+ }
+
+ enabledTextIds[TraceLogger_Interpreter] = enabledTextIds[TraceLogger_Engine];
+ enabledTextIds[TraceLogger_Baseline] = enabledTextIds[TraceLogger_Engine];
+ enabledTextIds[TraceLogger_IonMonkey] = enabledTextIds[TraceLogger_Engine];
+
+ enabledTextIds[TraceLogger_Error] = true;
+
+ const char* options = getenv("TLOPTIONS");
+ if (options) {
+ if (strstr(options, "help")) {
+ fflush(nullptr);
+ printf(
+ "\n"
+ "usage: TLOPTIONS=option,option,option,... where options can be:\n"
+ "\n"
+ " EnableMainThread Start logging main threads immediately.\n"
+ " EnableOffThread Start logging helper threads "
+ "immediately.\n"
+ " EnableGraph Enable the tracelogging graph.\n"
+ " EnableGraphFile Enable flushing tracelogger data to a "
+ "file.\n"
+ " Errors Report errors during tracing to "
+ "stderr.\n");
+ printf("\n");
+ exit(0);
+ /*NOTREACHED*/
+ }
+
+ if (strstr(options, "EnableMainThread")) {
+ mainThreadEnabled = true;
+ }
+ if (strstr(options, "EnableOffThread")) {
+ helperThreadEnabled = true;
+ }
+ if (strstr(options, "EnableGraph")) {
+ graphEnabled = true;
+ }
+ if (strstr(options, "EnableGraphFile")) {
+ graphFileEnabled = true;
+ jit::JitOptions.enableTraceLogger = true;
+ }
+ if (strstr(options, "Errors")) {
+ spewErrors = true;
+ }
+ } else {
+ mainThreadEnabled = true;
+ helperThreadEnabled = true;
+ graphEnabled = false;
+ graphFileEnabled = false;
+ spewErrors = false;
+ }
+
+ startTime = mozilla::TimeStamp::NowUnfuzzed();
+
+#ifdef DEBUG
+ initialized = true;
+#endif
+
+ return true;
+}
+
+void TraceLoggerThreadState::enableTextId(JSContext* cx, uint32_t textId) {
+ MOZ_ASSERT(TLTextIdIsTogglable(textId));
+
+ if (enabledTextIds[textId]) {
+ return;
+ }
+
+ ReleaseAllJITCode(cx->runtime()->defaultFreeOp());
+
+ enabledTextIds[textId] = true;
+ if (textId == TraceLogger_Engine) {
+ enabledTextIds[TraceLogger_IonMonkey] = true;
+ enabledTextIds[TraceLogger_Baseline] = true;
+ enabledTextIds[TraceLogger_Interpreter] = true;
+ }
+
+ if (textId == TraceLogger_Scripts) {
+ jit::ToggleBaselineTraceLoggerScripts(cx->runtime(), true);
+ }
+ if (textId == TraceLogger_Engine) {
+ jit::ToggleBaselineTraceLoggerEngine(cx->runtime(), true);
+ }
+}
+void TraceLoggerThreadState::disableTextId(JSContext* cx, uint32_t textId) {
+ MOZ_ASSERT(TLTextIdIsTogglable(textId));
+
+ if (!enabledTextIds[textId]) {
+ return;
+ }
+
+ ReleaseAllJITCode(cx->runtime()->defaultFreeOp());
+
+ enabledTextIds[textId] = false;
+ if (textId == TraceLogger_Engine) {
+ enabledTextIds[TraceLogger_IonMonkey] = false;
+ enabledTextIds[TraceLogger_Baseline] = false;
+ enabledTextIds[TraceLogger_Interpreter] = false;
+ }
+
+ if (textId == TraceLogger_Scripts) {
+ jit::ToggleBaselineTraceLoggerScripts(cx->runtime(), false);
+ }
+ if (textId == TraceLogger_Engine) {
+ jit::ToggleBaselineTraceLoggerEngine(cx->runtime(), false);
+ }
+}
+
+TraceLoggerThread* js::TraceLoggerForCurrentThread(JSContext* maybecx) {
+ if (!traceLoggerState) {
+ return nullptr;
+ }
+ return traceLoggerState->forCurrentThread(maybecx);
+}
+
+TraceLoggerThread* TraceLoggerThreadState::forCurrentThread(
+ JSContext* maybecx) {
+ if (!jit::JitOptions.enableTraceLogger) {
+ return nullptr;
+ }
+
+ MOZ_ASSERT(initialized);
+ MOZ_ASSERT_IF(maybecx, maybecx == TlsContext.get());
+
+ JSContext* cx = maybecx ? maybecx : TlsContext.get();
+ if (!cx) {
+ return nullptr;
+ }
+
+ if (!cx->traceLogger) {
+ LockGuard<Mutex> guard(lock);
+
+ TraceLoggerThread* logger = js_new<TraceLoggerThread>(cx);
+ if (!logger) {
+ return nullptr;
+ }
+
+ if (!logger->init()) {
+ return nullptr;
+ }
+
+ threadLoggers.insertFront(logger);
+ cx->traceLogger = logger;
+
+ if (graphEnabled) {
+ logger->initGraph();
+ }
+
+ if (cx->isHelperThreadContext() ? helperThreadEnabled : mainThreadEnabled) {
+ logger->enable();
+ }
+ }
+
+ return cx->traceLogger;
+}
+
+void TraceLoggerThreadState::destroyLogger(TraceLoggerThread* logger) {
+ MOZ_ASSERT(initialized);
+ MOZ_ASSERT(logger);
+ LockGuard<Mutex> guard(lock);
+
+ logger->remove();
+ js_delete(logger);
+}
+
+bool js::TraceLogTextIdEnabled(uint32_t textId) {
+ if (!traceLoggerState) {
+ return false;
+ }
+ return traceLoggerState->isTextIdEnabled(textId);
+}
+
+void js::TraceLogEnableTextId(JSContext* cx, uint32_t textId) {
+ if (!traceLoggerState) {
+ return;
+ }
+ traceLoggerState->enableTextId(cx, textId);
+}
+void js::TraceLogDisableTextId(JSContext* cx, uint32_t textId) {
+ if (!traceLoggerState) {
+ return;
+ }
+ traceLoggerState->disableTextId(cx, textId);
+}
+
+TraceLoggerEvent::TraceLoggerEvent(TraceLoggerTextId type, JSScript* script)
+ : TraceLoggerEvent(type, script->filename(), script->lineno(),
+ script->column()) {}
+
+TraceLoggerEvent::TraceLoggerEvent(TraceLoggerTextId type, const char* filename,
+ uint32_t line, uint32_t column)
+ : payload_() {
+ MOZ_ASSERT(
+ type == TraceLogger_Scripts || type == TraceLogger_AnnotateScripts ||
+ type == TraceLogger_InlinedScripts || type == TraceLogger_Frontend);
+
+ if (!traceLoggerState || !jit::JitOptions.enableTraceLogger) {
+ return;
+ }
+
+ // Only log scripts when enabled, otherwise use the more generic type
+ // (which will get filtered out).
+ if (!traceLoggerState->isTextIdEnabled(type)) {
+ payload_.setTextId(type);
+ return;
+ }
+
+ payload_.setEventPayload(
+ traceLoggerState->getOrCreateEventPayload(filename, line, column));
+}
+
+TraceLoggerEvent::TraceLoggerEvent(const char* text) : payload_() {
+ if (jit::JitOptions.enableTraceLogger && traceLoggerState) {
+ payload_.setEventPayload(traceLoggerState->getOrCreateEventPayload(text));
+ }
+}
+
+TraceLoggerEvent::~TraceLoggerEvent() {
+ if (hasExtPayload()) {
+ extPayload()->release();
+ }
+}
+
+uint32_t TraceLoggerEvent::textId() const {
+ MOZ_ASSERT(hasTextId());
+ if (hasExtPayload()) {
+ return extPayload()->textId();
+ }
+ return payload_.textId();
+}
+
+TraceLoggerEvent& TraceLoggerEvent::operator=(const TraceLoggerEvent& other) {
+ if (other.hasExtPayload()) {
+ other.extPayload()->use();
+ }
+ if (hasExtPayload()) {
+ extPayload()->release();
+ }
+
+ payload_ = other.payload_;
+
+ return *this;
+}
+
+TraceLoggerEvent::TraceLoggerEvent(const TraceLoggerEvent& other)
+ : payload_(other.payload_) {
+ if (hasExtPayload()) {
+ extPayload()->use();
+ }
+}
+
+JS_PUBLIC_API bool JS::InitTraceLogger() {
+ MOZ_RELEASE_ASSERT(!traceLoggerState);
+
+ if (!getTraceLoggerSupported()) {
+ return true;
+ }
+
+ traceLoggerState = js_new<TraceLoggerThreadState>();
+ if (!traceLoggerState) {
+ return false;
+ }
+
+ if (!traceLoggerState->init()) {
+ DestroyTraceLoggerThreadState();
+ return false;
+ }
+
+ return true;
+}
+
+JS_PUBLIC_API bool JS::TraceLoggerSupported() { return traceLoggerState; }
+
+// Perform a process wide synchronous spew of every thread that tracelogger has
+// captured.
+void TraceLoggerThreadState::spewTraceLoggerStats() {
+ for (TraceLoggerThread* logger : threadLoggers) {
+ logger->spewTraceLoggerStats();
+ }
+}
+
+// Usage here is JS_TRACELOGGER_SPEW=<event1>,<event2>,etc for custom spewing.
+// If the environment variable is not found, we use a default set of events.
+static bool getSpewIds(EventVector& spewIds) {
+ const char* env = getenv("JS_TRACELOGGER_SPEW");
+ if (env) {
+ for (uint32_t i = 1; i < TraceLogger_Last; i++) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ if (ContainsFlag(env, TLTextIdString(id))) {
+ if (!spewIds.append(id)) {
+ return false;
+ }
+ }
+ }
+ } else {
+ const uint32_t defaultSpewEvents[] = {
+ TraceLogger_ParsingFull, TraceLogger_Interpreter,
+ TraceLogger_Baseline, TraceLogger_BaselineCompilation,
+ TraceLogger_IonMonkey, TraceLogger_IonCompilation,
+ TraceLogger_Bailout};
+
+ for (uint32_t id : defaultSpewEvents) {
+ if (!spewIds.append(id)) {
+ return false;
+ }
+ }
+ }
+
+ return true;
+}
+
+static void spewHeaderRow(UniqueChars& threadName, EventVector& spewIds) {
+ if (threadName) {
+ JitSpew(jit::JitSpew_ScriptStats, "Thread: %s (pid=%d)", threadName.get(),
+ getpid());
+ } else {
+ JitSpew(jit::JitSpew_ScriptStats, "Unknown Thread (pid=%d)", getpid());
+ }
+
+ UniqueChars header = JS_smprintf("%10s ", "totalTime");
+ for (uint32_t i : spewIds) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ if (TLTextIdIsLogEvent(id)) {
+ header =
+ JS_sprintf_append(std::move(header), "%12s ", TLTextIdString(id));
+ } else {
+ header =
+ JS_sprintf_append(std::move(header), "%25s ", TLTextIdString(id));
+ }
+ }
+
+ JitSpew(jit::JitSpew_ScriptStats, "%s Script", header.get());
+}
+
+void TraceLoggerThread::spewTraceLoggerStats() {
+ if (!jit::JitOptions.enableTraceLogger) {
+ return;
+ }
+
+ ScriptMap map;
+ if (!collectTraceLoggerStats(map)) {
+ return;
+ }
+ if (map.empty()) {
+ return;
+ }
+
+ SortedStatsVector sorted_map;
+ if (!sortTraceLoggerStats(map, sorted_map)) {
+ return;
+ }
+ map.clearAndCompact();
+
+ EventVector spewIds;
+ if (!getSpewIds(spewIds)) {
+ return;
+ }
+
+ // Dynamically generate the header row in JitSpew.
+ spewHeaderRow(threadName_, spewIds);
+
+ for (UniquePtr<ScriptStats>& datap : sorted_map) {
+ auto& tlevents = datap->events_;
+ uint32_t selfTime = datap->selfTime;
+
+ if (selfTime == 0) {
+ continue;
+ }
+
+ UniqueChars row = JS_smprintf("%10u ", selfTime);
+ for (uint32_t i : spewIds) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ uint32_t time = tlevents[id].time;
+ uint32_t freq = tlevents[id].count;
+ uint32_t percent = (time * 100) / selfTime;
+ if (TLTextIdIsLogEvent(id)) {
+ row = JS_sprintf_append(std::move(row), "%12u ", freq);
+ } else {
+ row = JS_sprintf_append(std::move(row), "%8u (%3u%%,f=%-7u) ", time,
+ percent, freq);
+ }
+ }
+ JitSpew(jit::JitSpew_ScriptStats, "%s %s", row.get(), datap->scriptName);
+
+ // If structured spewer is enabled, we might as well spew everything.
+ AutoStructuredSpewer spew(cx_, SpewChannel::ScriptStats, nullptr);
+ if (spew) {
+ spew->property("script", datap->scriptName);
+ spew->property("totalTime", selfTime);
+ spew->beginListProperty("events");
+ for (uint32_t i = 1; i < TraceLogger_Last; i++) {
+ TraceLoggerTextId id = TraceLoggerTextId(i);
+ if (TLTextIdIsInternalEvent(id) || tlevents[id].count == 0) {
+ continue;
+ }
+
+ spew->beginObject();
+ spew->property("id", TLTextIdString(id));
+ if (TLTextIdIsTreeEvent(id)) {
+ spew->property("time", tlevents[id].time);
+ spew->property("frequency", tlevents[id].count);
+ } else if (TLTextIdIsLogEvent(id)) {
+ spew->property("frequency", tlevents[id].count);
+ }
+ spew->endObject();
+ }
+ spew->endList();
+ }
+ }
+}
+
+static bool updateScriptMap(ScriptMap& map, char* key, uint32_t eventId,
+ uint32_t value) {
+ if (!key) {
+ return false;
+ }
+
+ if (!map.has(key)) {
+ UniquePtr<ScriptStats> datap;
+ datap.reset(js_new<ScriptStats>(key));
+ if (!map.putNew(key, std::move(datap))) {
+ return false;
+ }
+ }
+ ScriptMap::Ptr p = map.lookup(key);
+ p->value()->events_[eventId].time += value;
+ p->value()->events_[eventId].count++;
+
+ if (TLTextIdIsTreeEvent(eventId)) {
+ p->value()->selfTime += value;
+ }
+ return true;
+}
+
+UniqueChars TraceLoggerThreadState::getFullScriptName(uint32_t textId) {
+ TraceLoggerEventPayload* payload = getPayload(textId);
+ MOZ_ASSERT(payload);
+ if (!payload) {
+ return nullptr;
+ }
+ char* filename = dictionaryData[payload->dictionaryId()].get();
+ uint32_t lineno = payload->line() ? *(payload->line()) : 0;
+ uint32_t colno = payload->column() ? *(payload->column()) : 0;
+ UniqueChars scriptName = JS_smprintf("%s:%u:%u", filename, lineno, colno);
+ payload->release();
+ return scriptName;
+}
+
+static bool sortBySelfTime(const UniquePtr<ScriptStats>& lhs,
+ const UniquePtr<ScriptStats>& rhs) {
+ return lhs.get()->selfTime > rhs.get()->selfTime;
+}
+
+bool TraceLoggerThread::sortTraceLoggerStats(ScriptMap& map,
+ SortedStatsVector& sorted_map) {
+ for (auto range = map.all(); !range.empty(); range.popFront()) {
+ if (!sorted_map.append(std::move(range.front().value()))) {
+ return false;
+ }
+ }
+
+ std::sort(sorted_map.begin(), sorted_map.end(), sortBySelfTime);
+
+ return true;
+}
+
+// Traverse each event and calculate the self-time, along with the script that
+// each event belongs to. We do this quickly by maintaining two stacks:
+// (i) eventStack - Each new event encountered is pushed onto the stack. Events
+// are popped off whenever a TraceLogger_Stop is encountered
+// and sent to updateScriptMap.
+// (ii) funcStack - Each new script encountered is pushed onto this stack.
+// Elements are popped off whenever a TraceLogger_Stop is
+// encountered that matches a script event on the top of
+// eventStack.
+bool TraceLoggerThread::collectTraceLoggerStats(ScriptMap& map) {
+ uint32_t totalJSTime = 0;
+
+ struct eventInfo {
+ uint32_t textId;
+ uint32_t time;
+ mozilla::TimeStamp start;
+
+ explicit eventInfo(uint32_t textId_) : textId(textId_), time(0) {}
+ };
+
+ Vector<eventInfo*, 0, js::SystemAllocPolicy> eventStack;
+ Vector<uint32_t, 0, js::SystemAllocPolicy> funcStack;
+
+ mozilla::TimeStamp startTime, stopTime;
+ uint32_t size = events_.size();
+ for (size_t i = 0; i < size; i++) {
+ uint32_t textId = events_[i].textId;
+
+ // Record any log events that have no durations such as Bailouts with a
+ // value of 1. Make sure the funcStack actually has something in it or
+ // else the Bailout event will not be associated with any script. This
+ // can commonly occur when profiling & tracing starts since we may have
+ // already past the point where the script event is created.
+ if (TLTextIdIsLogEvent(textId) && !funcStack.empty()) {
+ UniqueChars script =
+ traceLoggerState->getFullScriptName(funcStack.back());
+ if (!updateScriptMap(map, script.release(), textId, 1)) {
+ return false;
+ }
+ }
+
+ // Hit a new tree event or a stop event, so add (new event timestamp - old
+ // event timestamp) to the old event's self-time.
+ if (TLTextIdIsTreeEvent(textId)) {
+ if (!eventStack.empty()) {
+ stopTime = events_[i].time;
+
+ uint32_t deltaTime =
+ static_cast<uint32_t>((stopTime - startTime).ToMicroseconds());
+ eventStack.back()->time += deltaTime;
+
+ if (TLTextIdIsEnumEvent(eventStack.back()->textId)) {
+ if (!funcStack.empty() && !eventStack.empty()) {
+ UniqueChars script =
+ traceLoggerState->getFullScriptName(funcStack.back());
+ if (!updateScriptMap(map, script.release(),
+ eventStack.back()->textId, deltaTime)) {
+ return false;
+ }
+ }
+ }
+ totalJSTime += deltaTime;
+ }
+
+ if (TLTextIdIsScriptEvent(textId)) {
+ if (!funcStack.append(textId)) {
+ return false;
+ }
+ }
+
+ eventInfo* entry = js_new<eventInfo>(textId);
+ entry->start = events_[i].time;
+ if (!eventStack.append(entry)) {
+ return false;
+ }
+
+ startTime = events_[i].time;
+
+ } else if (textId == TraceLogger_Stop) {
+ if (!eventStack.empty()) {
+ stopTime = events_[i].time;
+
+ uint32_t deltaTime =
+ static_cast<uint32_t>((stopTime - startTime).ToMicroseconds());
+ eventInfo* entry = eventStack.popCopy();
+
+ uint32_t topId = entry->textId;
+ entry->time += deltaTime;
+
+ if (TLTextIdIsEnumEvent(topId)) {
+ // funcStack will usually be empty near the beginning of a profiling
+ // session since we may have skipped the point where the script event
+ // is created. If that's the case, then skip this event since we
+ // cannot associate it with any script.
+ if (!funcStack.empty()) {
+ UniqueChars script =
+ traceLoggerState->getFullScriptName(funcStack.back());
+ if (!updateScriptMap(map, script.release(), topId, deltaTime)) {
+ return false;
+ }
+ }
+ }
+ js_delete(entry);
+
+ if (TLTextIdIsScriptEvent(topId) && !funcStack.empty()) {
+ funcStack.popBack();
+ }
+
+ totalJSTime += deltaTime;
+ startTime = events_[i].time;
+ }
+ }
+ }
+
+ return true;
+}
+
+JS_PUBLIC_API void JS::ResetTraceLogger(void) { js::ResetTraceLogger(); }
+
+JS_PUBLIC_API void JS::SpewTraceLoggerThread(JSContext* cx) {
+ if (!traceLoggerState) {
+ return;
+ }
+
+ if (cx && cx->traceLogger) {
+ cx->traceLogger->spewTraceLoggerStats();
+ }
+}
+
+JS_PUBLIC_API void JS::SpewTraceLoggerForCurrentProcess() {
+ if (!traceLoggerState) {
+ return;
+ }
+ traceLoggerState->spewTraceLoggerStats();
+}
+
+JS_PUBLIC_API void JS::StartTraceLogger(JSContext* cx) {
+ if (!traceLoggerState) {
+ return;
+ }
+
+ if (!jit::JitOptions.enableTraceLogger) {
+ LockGuard<Mutex> guard(traceLoggerState->lock);
+ traceLoggerState->enableTextIdsForProfiler();
+ jit::JitOptions.enableTraceLogger = true;
+ traceLoggerState->startTime = mozilla::TimeStamp::Now();
+ }
+
+ TraceLoggerThread* logger = traceLoggerState->forCurrentThread(cx);
+ if (logger) {
+ logger->enable();
+ }
+}
+
+JS_PUBLIC_API void JS::StopTraceLogger(JSContext* cx) {
+ if (!traceLoggerState) {
+ return;
+ }
+
+ if (jit::JitOptions.enableTraceLogger) {
+ LockGuard<Mutex> guard(traceLoggerState->lock);
+ traceLoggerState->disableTextIdsForProfiler();
+ jit::JitOptions.enableTraceLogger = false;
+ }
+
+ TraceLoggerThread* logger = traceLoggerState->forCurrentThread(cx);
+ if (logger) {
+ logger->disable();
+ }
+}
generated by cgit v1.2.3 (git 2.39.1) at 2024-12-17 15:33:44 +0000