1 files changed, 721 insertions, 0 deletions
diff --git a/js/src/vm/TraceLoggingGraph.cpp b/js/src/vm/TraceLoggingGraph.cpp
new file mode 100644
index 0000000000..921c19d3d0
--- /dev/null
+++ b/js/src/vm/TraceLoggingGraph.cpp
@@ -0,0 +1,721 @@
+/* -*- 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/TraceLoggingGraph.h"
+
+#ifdef XP_WIN
+#  include <process.h>
+#  define getpid _getpid
+#else
+#  include <unistd.h>
+#endif
+
+#include "mozilla/EndianUtils.h"
+#include "mozilla/MemoryReporting.h"
+#include "mozilla/ScopeExit.h"
+
+#include "js/Printf.h"
+#include "js/UniquePtr.h"
+#include "threading/LockGuard.h"
+#include "threading/Thread.h"
+#include "util/Text.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, ...) {
+  va_list ap;
+
+  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.
+
+  js::UniqueChars filename(js_pod_malloc<char>(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.%u.tl\", \"events\":\"tl-event.%u.%u.tl\", "
+      "\"dict\":\"tl-dict.%u.%u.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, R"(, "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++;
+}
+
+size_t TraceLoggerGraphState::sizeOfExcludingThis(
+    mozilla::MallocSizeOf mallocSizeOf) const {
+  return 0;
+}
+
+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;
+}
+
+size_t js::SizeOfTraceLogGraphState(mozilla::MallocSizeOf mallocSizeOf) {
+  return traceLoggerGraphState
+             ? traceLoggerGraphState->sizeOfIncludingThis(mallocSizeOf)
+             : 0;
+}
+
+void js::DestroyTraceLoggerGraphState() {
+  if (traceLoggerGraphState) {
+    js_delete(traceLoggerGraphState);
+    traceLoggerGraphState = nullptr;
+  }
+}
+
+bool TraceLoggerGraph::init(uint64_t startTimestamp, bool graphFileEnabled) {
+  auto fail = MakeScopeExit([&] { failed = true; });
+
+  if (graphFileEnabled) {
+    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.%u.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.%u.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.%u.tl", pid, loggerId);
+    eventFile = fopen(eventFilename.get(), "wb");
+    if (!eventFile) {
+      return false;
+    }
+    auto cleanupEvent = MakeScopeExit([&] {
+      fclose(eventFile);
+      eventFile = nullptr;
+    });
+
+    if (fprintf(dictFile, "[") < 0) {
+      fprintf(stderr, "TraceLogging: Error while writing.\n");
+      return false;
+    }
+
+    cleanupDict.release();
+    cleanupTree.release();
+    cleanupEvent.release();
+  }
+
+  if (!tree.init()) {
+    return false;
+  }
+  if (!stack.init()) {
+    return false;
+  }
+
+  // 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);
+
+  fail.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 (!treeFile) {
+        disable(timestamp);
+        return;
+      }
+
+      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);
+  }
+
+  if (!eventFile) {
+    return;
+  }
+
+  // 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;
+  }
+
+  // If treeFile is null and treeOffset is non-zero then something is wrong
+  if (!treeFile) {
+    return false;
+  }
+
+  // Entry has been flushed to disk. Look it up.
+  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) {
+  MOZ_ASSERT(treeFile != nullptr);
+  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 (treeFile && !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 (treeFile && !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 (treeFile && !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,
+                           mozilla::TimeStamp startTime) {
+  for (uint32_t i = 0; i < events.size(); i++) {
+    mozilla::TimeDuration delta = events[i].time - startTime;
+    uint64_t timeOffset = static_cast<uint64_t>(delta.ToMicroseconds());
+
+    if (events[i].textId == TraceLogger_Stop) {
+      stopEvent(timeOffset);
+    } else if (TLTextIdIsTreeEvent(events[i].textId)) {
+      startEvent(events[i].textId, timeOffset);
+    } else {
+      logTimestamp(events[i].textId, timeOffset);
+    }
+  }
+}
+
+void TraceLoggerGraph::addTextId(uint32_t id, const char* text) {
+  mozilla::Maybe<uint32_t> line = mozilla::Nothing();
+  mozilla::Maybe<uint32_t> column = mozilla::Nothing();
+  addTextId(id, text, line, column);
+}
+
+void TraceLoggerGraph::addTextId(uint32_t id, const char* text,
+                                 mozilla::Maybe<uint32_t>& line,
+                                 mozilla::Maybe<uint32_t>& column) {
+  if (failed) {
+    return;
+  }
+
+  // Assume ids are given in order. Which is currently true.
+  MOZ_ASSERT(id == nextTextId_);
+  nextTextId_++;
+
+  if (id > 0) {
+    int written = fprintf(dictFile, ",\n");
+    if (written < 0) {
+      failed = true;
+      return;
+    }
+  }
+
+  js::UniqueChars str;
+  if (line && column) {
+    str = JS_smprintf("script %s:%u:%u", text, *line, *column);
+  } else if (line) {
+    str = JS_smprintf("script %s:%u", text, *line);
+  } else {
+    str = JS_smprintf("%s", text);
+  }
+
+  if (!js::FileEscapedString(dictFile, str.get(), strlen(str.get()), '"')) {
+    failed = true;
+  }
+  str.reset();
+}
+
+size_t TraceLoggerGraph::sizeOfExcludingThis(
+    mozilla::MallocSizeOf mallocSizeOf) const {
+  size_t size = 0;
+  size += tree.sizeOfExcludingThis(mallocSizeOf);
+  size += stack.sizeOfExcludingThis(mallocSizeOf);
+  return size;
+}
+
+size_t TraceLoggerGraph::sizeOfIncludingThis(
+    mozilla::MallocSizeOf mallocSizeOf) const {
+  return mallocSizeOf(this) + sizeOfExcludingThis(mallocSizeOf);
+}
+
+#undef getpid