summaryrefslogtreecommitdiffstats
path: root/js/src/vm/TraceLoggingGraph.cpp
diff options
context:
space:
mode:
Diffstat (limited to 'js/src/vm/TraceLoggingGraph.cpp')
-rw-r--r--js/src/vm/TraceLoggingGraph.cpp649
1 files changed, 649 insertions, 0 deletions
diff --git a/js/src/vm/TraceLoggingGraph.cpp b/js/src/vm/TraceLoggingGraph.cpp
new file mode 100644
index 000000000..6f6792e98
--- /dev/null
+++ b/js/src/vm/TraceLoggingGraph.cpp
@@ -0,0 +1,649 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
+ * vim: set ts=8 sts=4 et sw=4 tw=99:
+ * 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/TraceLoggingGraph.h"
+
+#ifdef XP_WIN
+#include <process.h>
+#define getpid _getpid
+#else
+#include <unistd.h>
+#endif
+
+#include "mozilla/EndianUtils.h"
+#include "mozilla/ScopeExit.h"
+
+#include "jsstr.h"
+
+#include "js/UniquePtr.h"
+#include "threading/LockGuard.h"
+#include "threading/Thread.h"
+#include "vm/TraceLogging.h"
+
+#ifndef DEFAULT_TRACE_LOG_DIR
+# if defined(_WIN32)
+# define DEFAULT_TRACE_LOG_DIR "."
+# else
+# define DEFAULT_TRACE_LOG_DIR "/tmp/"
+# endif
+#endif
+
+using mozilla::MakeScopeExit;
+using mozilla::NativeEndian;
+
+TraceLoggerGraphState* traceLoggerGraphState = nullptr;
+
+// gcc and clang have these in symcat.h, but MSVC does not.
+#ifndef STRINGX
+# define STRINGX(x) #x
+#endif
+#ifndef XSTRING
+# define XSTRING(macro) STRINGX(macro)
+#endif
+
+#define MAX_LOGGERS 999
+
+// Return a filename relative to the output directory. %u and %d substitutions
+// are allowed, with %u standing for a full 32-bit number and %d standing for
+// an up to 3-digit number.
+static js::UniqueChars
+MOZ_FORMAT_PRINTF(1, 2)
+AllocTraceLogFilename(const char* pattern, ...) {
+ js::UniqueChars filename;
+
+ va_list ap;
+
+ static const char* outdir = getenv("TLDIR") ? getenv("TLDIR") : DEFAULT_TRACE_LOG_DIR;
+ size_t len = strlen(outdir) + 1; // "+ 1" is for the '/'
+
+ for (const char* p = pattern; *p; p++) {
+ if (*p == '%') {
+ p++;
+ if (*p == 'u')
+ len += sizeof("4294967295") - 1;
+ else if (*p == 'd')
+ len += sizeof(XSTRING(MAX_LOGGERS)) - 1;
+ else
+ MOZ_CRASH("Invalid format");
+ } else {
+ len++;
+ }
+ }
+
+ len++; // For the terminating NUL.
+
+ filename.reset((char*) js_malloc(len));
+ if (!filename)
+ return nullptr;
+ char* rest = filename.get() + sprintf(filename.get(), "%s/", outdir);
+
+ va_start(ap, pattern);
+ int ret = vsnprintf(rest, len, pattern, ap);
+ va_end(ap);
+ if (ret < 0)
+ return nullptr;
+
+ MOZ_ASSERT(size_t(ret) <= len - (strlen(outdir) + 1),
+ "overran TL filename buffer; %d given too large a value?");
+
+ return filename;
+}
+
+bool
+TraceLoggerGraphState::init()
+{
+ pid_ = (uint32_t) getpid();
+
+ js::UniqueChars filename = AllocTraceLogFilename("tl-data.%u.json", pid_);
+ out = fopen(filename.get(), "w");
+ if (!out) {
+ fprintf(stderr, "warning: failed to create TraceLogger output file %s\n", filename.get());
+ return false;
+ }
+
+ fprintf(out, "[");
+
+ // Write the latest tl-data.*.json file to tl-data.json.
+ // In most cases that is the wanted file.
+ js::UniqueChars masterFilename = AllocTraceLogFilename("tl-data.json");
+ if (FILE* last = fopen(masterFilename.get(), "w")) {
+ char *basename = strrchr(filename.get(), '/');
+ basename = basename ? basename + 1 : filename.get();
+ fprintf(last, "\"%s\"", basename);
+ fclose(last);
+ }
+
+#ifdef DEBUG
+ initialized = true;
+#endif
+ return true;
+}
+
+TraceLoggerGraphState::~TraceLoggerGraphState()
+{
+ if (out) {
+ fprintf(out, "]");
+ fclose(out);
+ out = nullptr;
+ }
+
+#ifdef DEBUG
+ initialized = false;
+#endif
+}
+
+uint32_t
+TraceLoggerGraphState::nextLoggerId()
+{
+ js::LockGuard<js::Mutex> guard(lock);
+
+ MOZ_ASSERT(initialized);
+
+ if (numLoggers > MAX_LOGGERS) {
+ fputs("TraceLogging: Can't create more than " XSTRING(MAX_LOGGERS) " different loggers.",
+ stderr);
+ return uint32_t(-1);
+ }
+
+ if (numLoggers > 0) {
+ int written = fprintf(out, ",\n");
+ if (written < 0) {
+ fprintf(stderr, "TraceLogging: Error while writing.\n");
+ return uint32_t(-1);
+ }
+ }
+
+ int written = fprintf(out, "{\"tree\":\"tl-tree.%u.%d.tl\", \"events\":\"tl-event.%u.%d.tl\", "
+ "\"dict\":\"tl-dict.%u.%d.json\", \"treeFormat\":\"64,64,31,1,32\"",
+ pid_, numLoggers, pid_, numLoggers, pid_, numLoggers);
+
+ if (written > 0) {
+ char threadName[16];
+ js::ThisThread::GetName(threadName, sizeof(threadName));
+ if (threadName[0])
+ written = fprintf(out, ", \"threadName\":\"%s\"", threadName);
+ }
+
+ if (written > 0)
+ written = fprintf(out, "}");
+
+ if (written < 0) {
+ fprintf(stderr, "TraceLogging: Error while writing.\n");
+ return uint32_t(-1);
+ }
+
+ return numLoggers++;
+}
+
+static bool
+EnsureTraceLoggerGraphState()
+{
+ if (MOZ_LIKELY(traceLoggerGraphState))
+ return true;
+
+ traceLoggerGraphState = js_new<TraceLoggerGraphState>();
+ if (!traceLoggerGraphState)
+ return false;
+
+ if (!traceLoggerGraphState->init()) {
+ js::DestroyTraceLoggerGraphState();
+ return false;
+ }
+
+ return true;
+}
+
+void
+js::DestroyTraceLoggerGraphState()
+{
+ if (traceLoggerGraphState) {
+ js_delete(traceLoggerGraphState);
+ traceLoggerGraphState = nullptr;
+ }
+}
+
+bool
+TraceLoggerGraph::init(uint64_t startTimestamp)
+{
+ auto fail = MakeScopeExit([&] { failed = true; });
+
+ if (!tree.init())
+ return false;
+ if (!stack.init())
+ return false;
+
+ if (!EnsureTraceLoggerGraphState())
+ return false;
+
+ uint32_t loggerId = traceLoggerGraphState->nextLoggerId();
+ if (loggerId == uint32_t(-1))
+ return false;
+
+ uint32_t pid = traceLoggerGraphState->pid();
+
+ js::UniqueChars dictFilename = AllocTraceLogFilename("tl-dict.%u.%d.json", pid, loggerId);
+ dictFile = fopen(dictFilename.get(), "w");
+ if (!dictFile)
+ return false;
+ auto cleanupDict = MakeScopeExit([&] { fclose(dictFile); dictFile = nullptr; });
+
+ js::UniqueChars treeFilename = AllocTraceLogFilename("tl-tree.%u.%d.tl", pid, loggerId);
+ treeFile = fopen(treeFilename.get(), "w+b");
+ if (!treeFile)
+ return false;
+ auto cleanupTree = MakeScopeExit([&] { fclose(treeFile); treeFile = nullptr; });
+
+ js::UniqueChars eventFilename = AllocTraceLogFilename("tl-event.%u.%d.tl", pid, loggerId);
+ eventFile = fopen(eventFilename.get(), "wb");
+ if (!eventFile)
+ return false;
+ auto cleanupEvent = MakeScopeExit([&] { fclose(eventFile); eventFile = nullptr; });
+
+ // Create the top tree node and corresponding first stack item.
+ TreeEntry& treeEntry = tree.pushUninitialized();
+ treeEntry.setStart(startTimestamp);
+ treeEntry.setStop(0);
+ treeEntry.setTextId(0);
+ treeEntry.setHasChildren(false);
+ treeEntry.setNextId(0);
+
+ StackEntry& stackEntry = stack.pushUninitialized();
+ stackEntry.setTreeId(0);
+ stackEntry.setLastChildId(0);
+ stackEntry.setActive(true);
+
+ if (fprintf(dictFile, "[") < 0) {
+ fprintf(stderr, "TraceLogging: Error while writing.\n");
+ return false;
+ }
+
+ fail.release();
+ cleanupDict.release();
+ cleanupTree.release();
+ cleanupEvent.release();
+
+ return true;
+}
+
+TraceLoggerGraph::~TraceLoggerGraph()
+{
+ // Write dictionary to disk
+ if (dictFile) {
+ int written = fprintf(dictFile, "]");
+ if (written < 0)
+ fprintf(stderr, "TraceLogging: Error while writing.\n");
+ fclose(dictFile);
+
+ dictFile = nullptr;
+ }
+
+ if (!failed && treeFile) {
+ // Make sure every start entry has a corresponding stop value.
+ // We temporarily enable logging for this. Stop doesn't need any extra data,
+ // so is safe to do even when we have encountered OOM.
+ enabled = true;
+ while (stack.size() > 1)
+ stopEvent(0);
+ enabled = false;
+ }
+
+ if (!failed && !flush()) {
+ fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
+ enabled = false;
+ failed = true;
+ }
+
+ if (treeFile) {
+ fclose(treeFile);
+ treeFile = nullptr;
+ }
+
+ if (eventFile) {
+ fclose(eventFile);
+ eventFile = nullptr;
+ }
+}
+
+bool
+TraceLoggerGraph::flush()
+{
+ MOZ_ASSERT(!failed);
+
+ if (treeFile) {
+ // Format data in big endian.
+ for (size_t i = 0; i < tree.size(); i++)
+ entryToBigEndian(&tree[i]);
+
+ int success = fseek(treeFile, 0, SEEK_END);
+ if (success != 0)
+ return false;
+
+ size_t bytesWritten = fwrite(tree.data(), sizeof(TreeEntry), tree.size(), treeFile);
+ if (bytesWritten < tree.size())
+ return false;
+
+ treeOffset += tree.size();
+ tree.clear();
+ }
+
+ return true;
+}
+
+void
+TraceLoggerGraph::entryToBigEndian(TreeEntry* entry)
+{
+ entry->start_ = NativeEndian::swapToBigEndian(entry->start_);
+ entry->stop_ = NativeEndian::swapToBigEndian(entry->stop_);
+ uint32_t data = (entry->u.s.textId_ << 1) + entry->u.s.hasChildren_;
+ entry->u.value_ = NativeEndian::swapToBigEndian(data);
+ entry->nextId_ = NativeEndian::swapToBigEndian(entry->nextId_);
+}
+
+void
+TraceLoggerGraph::entryToSystemEndian(TreeEntry* entry)
+{
+ entry->start_ = NativeEndian::swapFromBigEndian(entry->start_);
+ entry->stop_ = NativeEndian::swapFromBigEndian(entry->stop_);
+
+ uint32_t data = NativeEndian::swapFromBigEndian(entry->u.value_);
+ entry->u.s.textId_ = data >> 1;
+ entry->u.s.hasChildren_ = data & 0x1;
+
+ entry->nextId_ = NativeEndian::swapFromBigEndian(entry->nextId_);
+}
+
+void
+TraceLoggerGraph::startEvent(uint32_t id, uint64_t timestamp)
+{
+ if (failed || enabled == 0)
+ return;
+
+ if (!tree.hasSpaceForAdd()) {
+ if (tree.size() >= treeSizeFlushLimit() || !tree.ensureSpaceBeforeAdd()) {
+ if (!flush()) {
+ fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
+ enabled = false;
+ failed = true;
+ return;
+ }
+ }
+ }
+
+ if (!startEventInternal(id, timestamp)) {
+ fprintf(stderr, "TraceLogging: Failed to start an event.\n");
+ enabled = false;
+ failed = true;
+ return;
+ }
+}
+
+TraceLoggerGraph::StackEntry&
+TraceLoggerGraph::getActiveAncestor()
+{
+ uint32_t parentId = stack.lastEntryId();
+ while (!stack[parentId].active())
+ parentId--;
+ return stack[parentId];
+}
+
+bool
+TraceLoggerGraph::startEventInternal(uint32_t id, uint64_t timestamp)
+{
+ if (!stack.ensureSpaceBeforeAdd())
+ return false;
+
+ // Patch up the tree to be correct. There are two scenarios:
+ // 1) Parent has no children yet. So update parent to include children.
+ // 2) Parent has already children. Update last child to link to the new
+ // child.
+ StackEntry& parent = getActiveAncestor();
+#ifdef DEBUG
+ TreeEntry entry;
+ if (!getTreeEntry(parent.treeId(), &entry))
+ return false;
+#endif
+
+ if (parent.lastChildId() == 0) {
+ MOZ_ASSERT(!entry.hasChildren());
+ MOZ_ASSERT(parent.treeId() == treeOffset + tree.size() - 1);
+
+ if (!updateHasChildren(parent.treeId()))
+ return false;
+ } else {
+ MOZ_ASSERT(entry.hasChildren());
+
+ if (!updateNextId(parent.lastChildId(), tree.size() + treeOffset))
+ return false;
+ }
+
+ // Add a new tree entry.
+ TreeEntry& treeEntry = tree.pushUninitialized();
+ treeEntry.setStart(timestamp);
+ treeEntry.setStop(0);
+ treeEntry.setTextId(id);
+ treeEntry.setHasChildren(false);
+ treeEntry.setNextId(0);
+
+ // Add a new stack entry.
+ StackEntry& stackEntry = stack.pushUninitialized();
+ stackEntry.setTreeId(tree.lastEntryId() + treeOffset);
+ stackEntry.setLastChildId(0);
+ stackEntry.setActive(true);
+
+ // Set the last child of the parent to this newly added entry.
+ parent.setLastChildId(tree.lastEntryId() + treeOffset);
+
+ return true;
+}
+
+void
+TraceLoggerGraph::stopEvent(uint32_t id, uint64_t timestamp)
+{
+#ifdef DEBUG
+ if (id != TraceLogger_Scripts &&
+ id != TraceLogger_Engine &&
+ stack.size() > 1 &&
+ stack.lastEntry().active())
+ {
+ TreeEntry entry;
+ MOZ_ASSERT(getTreeEntry(stack.lastEntry().treeId(), &entry));
+ MOZ_ASSERT(entry.textId() == id);
+ }
+#endif
+
+ stopEvent(timestamp);
+}
+
+void
+TraceLoggerGraph::stopEvent(uint64_t timestamp)
+{
+ if (enabled && stack.lastEntry().active()) {
+ if (!updateStop(stack.lastEntry().treeId(), timestamp)) {
+ fprintf(stderr, "TraceLogging: Failed to stop an event.\n");
+ enabled = false;
+ failed = true;
+ return;
+ }
+ }
+ if (stack.size() == 1) {
+ if (!enabled)
+ return;
+
+ // Forcefully disable logging. We have no stack information anymore.
+ logTimestamp(TraceLogger_Disable, timestamp);
+ return;
+ }
+ stack.pop();
+}
+
+void
+TraceLoggerGraph::logTimestamp(uint32_t id, uint64_t timestamp)
+{
+ if (failed)
+ return;
+
+ if (id == TraceLogger_Enable)
+ enabled = true;
+
+ if (!enabled)
+ return;
+
+ if (id == TraceLogger_Disable)
+ disable(timestamp);
+
+ MOZ_ASSERT(eventFile);
+
+ // Format data in big endian
+ timestamp = NativeEndian::swapToBigEndian(timestamp);
+ id = NativeEndian::swapToBigEndian(id);
+
+ // The layout of the event log in the log file is:
+ // [timestamp, textId]
+ size_t itemsWritten = 0;
+ itemsWritten += fwrite(&timestamp, sizeof(uint64_t), 1, eventFile);
+ itemsWritten += fwrite(&id, sizeof(uint32_t), 1, eventFile);
+ if (itemsWritten < 2) {
+ failed = true;
+ enabled = false;
+ }
+}
+
+bool
+TraceLoggerGraph::getTreeEntry(uint32_t treeId, TreeEntry* entry)
+{
+ // Entry is still in memory
+ if (treeId >= treeOffset) {
+ *entry = tree[treeId - treeOffset];
+ return true;
+ }
+
+ int success = fseek(treeFile, treeId * sizeof(TreeEntry), SEEK_SET);
+ if (success != 0)
+ return false;
+
+ size_t itemsRead = fread((void*)entry, sizeof(TreeEntry), 1, treeFile);
+ if (itemsRead < 1)
+ return false;
+
+ entryToSystemEndian(entry);
+ return true;
+}
+
+bool
+TraceLoggerGraph::saveTreeEntry(uint32_t treeId, TreeEntry* entry)
+{
+ int success = fseek(treeFile, treeId * sizeof(TreeEntry), SEEK_SET);
+ if (success != 0)
+ return false;
+
+ entryToBigEndian(entry);
+
+ size_t itemsWritten = fwrite(entry, sizeof(TreeEntry), 1, treeFile);
+ if (itemsWritten < 1)
+ return false;
+
+ return true;
+}
+
+bool
+TraceLoggerGraph::updateHasChildren(uint32_t treeId, bool hasChildren)
+{
+ if (treeId < treeOffset) {
+ TreeEntry entry;
+ if (!getTreeEntry(treeId, &entry))
+ return false;
+ entry.setHasChildren(hasChildren);
+ if (!saveTreeEntry(treeId, &entry))
+ return false;
+ return true;
+ }
+
+ tree[treeId - treeOffset].setHasChildren(hasChildren);
+ return true;
+}
+
+bool
+TraceLoggerGraph::updateNextId(uint32_t treeId, uint32_t nextId)
+{
+ if (treeId < treeOffset) {
+ TreeEntry entry;
+ if (!getTreeEntry(treeId, &entry))
+ return false;
+ entry.setNextId(nextId);
+ if (!saveTreeEntry(treeId, &entry))
+ return false;
+ return true;
+ }
+
+ tree[treeId - treeOffset].setNextId(nextId);
+ return true;
+}
+
+bool
+TraceLoggerGraph::updateStop(uint32_t treeId, uint64_t timestamp)
+{
+ if (treeId < treeOffset) {
+ TreeEntry entry;
+ if (!getTreeEntry(treeId, &entry))
+ return false;
+ entry.setStop(timestamp);
+ if (!saveTreeEntry(treeId, &entry))
+ return false;
+ return true;
+ }
+
+ tree[treeId - treeOffset].setStop(timestamp);
+ return true;
+}
+
+void
+TraceLoggerGraph::disable(uint64_t timestamp)
+{
+ MOZ_ASSERT(enabled);
+ while (stack.size() > 1)
+ stopEvent(timestamp);
+
+ enabled = false;
+}
+
+void
+TraceLoggerGraph::log(ContinuousSpace<EventEntry>& events)
+{
+ for (uint32_t i = 0; i < events.size(); i++) {
+ if (events[i].textId == TraceLogger_Stop)
+ stopEvent(events[i].time);
+ else if (TLTextIdIsTreeEvent(events[i].textId))
+ startEvent(events[i].textId, events[i].time);
+ else
+ logTimestamp(events[i].textId, events[i].time);
+ }
+}
+
+void
+TraceLoggerGraph::addTextId(uint32_t id, const char* text)
+{
+ if (failed)
+ return;
+
+ // Assume ids are given in order. Which is currently true.
+#ifdef DEBUG
+ MOZ_ASSERT(id == nextTextId);
+ nextTextId++;
+#endif
+
+ if (id > 0) {
+ int written = fprintf(dictFile, ",\n");
+ if (written < 0) {
+ failed = true;
+ return;
+ }
+ }
+
+ if (!js::FileEscapedString(dictFile, text, strlen(text), '"'))
+ failed = true;
+}
+
+#undef getpid