1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/js/src/vm/TraceLogging.cpp Wed Dec 31 06:09:35 2014 +0100
1.3 @@ -0,0 +1,991 @@
1.4 +/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
1.5 + * vim: set ts=8 sts=4 et sw=4 tw=99:
1.6 + * This Source Code Form is subject to the terms of the Mozilla Public
1.7 + * License, v. 2.0. If a copy of the MPL was not distributed with this
1.8 + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
1.9 +
1.10 +#include "vm/TraceLogging.h"
1.11 +
1.12 +#include "mozilla/DebugOnly.h"
1.13 +
1.14 +#include <string.h>
1.15 +
1.16 +#include "jsapi.h"
1.17 +#include "jsscript.h"
1.18 +
1.19 +#include "jit/CompileWrappers.h"
1.20 +#include "vm/Runtime.h"
1.21 +
1.22 +using namespace js;
1.23 +
1.24 +#ifndef TRACE_LOG_DIR
1.25 +# if defined(_WIN32)
1.26 +# define TRACE_LOG_DIR ""
1.27 +# else
1.28 +# define TRACE_LOG_DIR "/tmp/"
1.29 +# endif
1.30 +#endif
1.31 +
1.32 +#if defined(__i386__)
1.33 +static __inline__ uint64_t
1.34 +rdtsc(void)
1.35 +{
1.36 + uint64_t x;
1.37 + __asm__ volatile (".byte 0x0f, 0x31" : "=A" (x));
1.38 + return x;
1.39 +}
1.40 +#elif defined(__x86_64__)
1.41 +static __inline__ uint64_t
1.42 +rdtsc(void)
1.43 +{
1.44 + unsigned hi, lo;
1.45 + __asm__ __volatile__ ("rdtsc" : "=a"(lo), "=d"(hi));
1.46 + return ( (uint64_t)lo)|( ((uint64_t)hi)<<32 );
1.47 +}
1.48 +#elif defined(__powerpc__)
1.49 +static __inline__ uint64_t
1.50 +rdtsc(void)
1.51 +{
1.52 + uint64_t result=0;
1.53 + uint32_t upper, lower,tmp;
1.54 + __asm__ volatile(
1.55 + "0: \n"
1.56 + "\tmftbu %0 \n"
1.57 + "\tmftb %1 \n"
1.58 + "\tmftbu %2 \n"
1.59 + "\tcmpw %2,%0 \n"
1.60 + "\tbne 0b \n"
1.61 + : "=r"(upper),"=r"(lower),"=r"(tmp)
1.62 + );
1.63 + result = upper;
1.64 + result = result<<32;
1.65 + result = result|lower;
1.66 +
1.67 + return result;
1.68 +}
1.69 +#endif
1.70 +
1.71 +TraceLogging traceLoggers;
1.72 +
1.73 +static const char* const text[] =
1.74 +{
1.75 + "TraceLogger failed to process text",
1.76 +#define NAME(x) #x,
1.77 + TRACELOGGER_TEXT_ID_LIST(NAME)
1.78 +#undef NAME
1.79 +};
1.80 +
1.81 +TraceLogger::TraceLogger()
1.82 + : enabled(false),
1.83 + enabledTimes(0),
1.84 + failed(false),
1.85 + nextTextId(0),
1.86 + treeOffset(0),
1.87 + top(nullptr)
1.88 +{ }
1.89 +
1.90 +bool
1.91 +TraceLogger::init(uint32_t loggerId)
1.92 +{
1.93 + if (!pointerMap.init())
1.94 + return false;
1.95 + if (!tree.init())
1.96 + return false;
1.97 + if (!stack.init())
1.98 + return false;
1.99 + if (!events.init())
1.100 + return false;
1.101 +
1.102 + MOZ_ASSERT(loggerId <= 999);
1.103 +
1.104 + char dictFilename[sizeof TRACE_LOG_DIR "tl-dict.100.json"];
1.105 + sprintf(dictFilename, TRACE_LOG_DIR "tl-dict.%d.json", loggerId);
1.106 + dictFile = fopen(dictFilename, "w");
1.107 + if (!dictFile)
1.108 + return false;
1.109 +
1.110 + char treeFilename[sizeof TRACE_LOG_DIR "tl-tree.100.tl"];
1.111 + sprintf(treeFilename, TRACE_LOG_DIR "tl-tree.%d.tl", loggerId);
1.112 + treeFile = fopen(treeFilename, "wb");
1.113 + if (!treeFile) {
1.114 + fclose(dictFile);
1.115 + dictFile = nullptr;
1.116 + return false;
1.117 + }
1.118 +
1.119 + char eventFilename[sizeof TRACE_LOG_DIR "tl-event.100.tl"];
1.120 + sprintf(eventFilename, TRACE_LOG_DIR "tl-event.%d.tl", loggerId);
1.121 + eventFile = fopen(eventFilename, "wb");
1.122 + if (!eventFile) {
1.123 + fclose(dictFile);
1.124 + fclose(treeFile);
1.125 + dictFile = nullptr;
1.126 + treeFile = nullptr;
1.127 + return false;
1.128 + }
1.129 +
1.130 + uint64_t start = rdtsc() - traceLoggers.startupTime;
1.131 +
1.132 + TreeEntry &treeEntry = tree.pushUninitialized();
1.133 + treeEntry.setStart(start);
1.134 + treeEntry.setStop(0);
1.135 + treeEntry.setTextId(0);
1.136 + treeEntry.setHasChildren(false);
1.137 + treeEntry.setNextId(0);
1.138 +
1.139 + StackEntry &stackEntry = stack.pushUninitialized();
1.140 + stackEntry.setTreeId(0);
1.141 + stackEntry.setLastChildId(0);
1.142 + stackEntry.setActive(true);
1.143 +
1.144 + int written = fprintf(dictFile, "[");
1.145 + if (written < 0)
1.146 + fprintf(stderr, "TraceLogging: Error while writing.\n");
1.147 +
1.148 + // Eagerly create the default textIds, to match their Tracelogger::TextId.
1.149 + for (uint32_t i = 0; i < LAST; i++) {
1.150 + mozilla::DebugOnly<uint32_t> textId = createTextId(text[i]);
1.151 + MOZ_ASSERT(textId == i);
1.152 + }
1.153 +
1.154 + enabled = true;
1.155 + enabledTimes = 1;
1.156 + return true;
1.157 +}
1.158 +
1.159 +bool
1.160 +TraceLogger::enable()
1.161 +{
1.162 + if (enabled) {
1.163 + enabledTimes++;
1.164 + return true;
1.165 + }
1.166 +
1.167 + if (failed)
1.168 + return false;
1.169 +
1.170 + if (!tree.ensureSpaceBeforeAdd(stack.size())) {
1.171 + if (!flush()) {
1.172 + fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
1.173 + failed = true;
1.174 + return false;
1.175 + }
1.176 + if (!tree.ensureSpaceBeforeAdd(stack.size())) {
1.177 + fprintf(stderr, "TraceLogging: Couldn't reserve enough space.\n");
1.178 + failed = true;
1.179 + return false;
1.180 + }
1.181 + }
1.182 +
1.183 + uint64_t start = rdtsc() - traceLoggers.startupTime;
1.184 + StackEntry *parent = &stack[0];
1.185 + for (uint32_t i = 1; i < stack.size(); i++) {
1.186 + if (!traceLoggers.isTextIdEnabled(stack[i].textId()))
1.187 + continue;
1.188 +#ifdef DEBUG
1.189 + TreeEntry entry;
1.190 + if (!getTreeEntry(parent->treeId(), &entry))
1.191 + return false;
1.192 +#endif
1.193 +
1.194 + if (parent->lastChildId() == 0) {
1.195 + MOZ_ASSERT(!entry.hasChildren());
1.196 + MOZ_ASSERT(parent->treeId() == tree.currentId() + treeOffset);
1.197 + if (!updateHasChildren(parent->treeId())) {
1.198 + fprintf(stderr, "TraceLogging: Couldn't update an entry.\n");
1.199 + failed = true;
1.200 + return false;
1.201 + }
1.202 + } else {
1.203 + MOZ_ASSERT(entry.hasChildren() == 1);
1.204 + if (!updateNextId(parent->lastChildId(), tree.nextId() + treeOffset)) {
1.205 + fprintf(stderr, "TraceLogging: Couldn't update an entry.\n");
1.206 + failed = true;
1.207 + return false;
1.208 + }
1.209 + }
1.210 +
1.211 + TreeEntry &treeEntry = tree.pushUninitialized();
1.212 + treeEntry.setStart(start);
1.213 + treeEntry.setStop(0);
1.214 + treeEntry.setTextId(stack[i].textId());
1.215 + treeEntry.setHasChildren(false);
1.216 + treeEntry.setNextId(0);
1.217 +
1.218 + stack[i].setActive(true);
1.219 + stack[i].setTreeId(tree.currentId() + treeOffset);
1.220 +
1.221 + parent->setLastChildId(tree.currentId() + treeOffset);
1.222 +
1.223 + parent = &stack[i];
1.224 + }
1.225 +
1.226 + enabled = true;
1.227 + enabledTimes = 1;
1.228 +
1.229 + return true;
1.230 +}
1.231 +
1.232 +bool
1.233 +TraceLogger::disable()
1.234 +{
1.235 + if (failed)
1.236 + return false;
1.237 +
1.238 + if (!enabled)
1.239 + return true;
1.240 +
1.241 + if (enabledTimes > 1) {
1.242 + enabledTimes--;
1.243 + return true;
1.244 + }
1.245 +
1.246 + uint64_t stop = rdtsc() - traceLoggers.startupTime;
1.247 + for (uint32_t i = 1; i < stack.size(); i++) {
1.248 + if (!stack[i].active())
1.249 + continue;
1.250 +
1.251 + if (!updateStop(stack[i].treeId(), stop)) {
1.252 + fprintf(stderr, "TraceLogging: Failed to stop an event.\n");
1.253 + failed = true;
1.254 + enabled = false;
1.255 + return false;
1.256 + }
1.257 +
1.258 + stack[i].setActive(false);
1.259 + }
1.260 +
1.261 +
1.262 + enabled = false;
1.263 + enabledTimes = 0;
1.264 +
1.265 + return true;
1.266 +}
1.267 +
1.268 +bool
1.269 +TraceLogger::flush()
1.270 +{
1.271 + MOZ_ASSERT(!failed);
1.272 +
1.273 + if (treeFile) {
1.274 + // Format data in big endian.
1.275 + for (size_t i = 0; i < tree.size(); i++)
1.276 + entryToBigEndian(&tree[i]);
1.277 +
1.278 + int success = fseek(treeFile, 0, SEEK_END);
1.279 + if (success != 0)
1.280 + return false;
1.281 +
1.282 + size_t bytesWritten = fwrite(tree.data(), sizeof(TreeEntry), tree.size(), treeFile);
1.283 + if (bytesWritten < tree.size())
1.284 + return false;
1.285 +
1.286 + treeOffset += tree.currentId();
1.287 + tree.clear();
1.288 + }
1.289 +
1.290 + if (eventFile) {
1.291 + // Format data in big endian
1.292 + for (size_t i = 0; i < events.size(); i++) {
1.293 + events[i].time = htobe64(events[i].time);
1.294 + events[i].textId = htobe64(events[i].textId);
1.295 + }
1.296 +
1.297 + size_t bytesWritten = fwrite(events.data(), sizeof(EventEntry), events.size(), eventFile);
1.298 + if (bytesWritten < events.size())
1.299 + return false;
1.300 + events.clear();
1.301 + }
1.302 +
1.303 + return true;
1.304 +}
1.305 +
1.306 +TraceLogger::~TraceLogger()
1.307 +{
1.308 + // Write dictionary to disk
1.309 + if (dictFile) {
1.310 + int written = fprintf(dictFile, "]");
1.311 + if (written < 0)
1.312 + fprintf(stderr, "TraceLogging: Error while writing.\n");
1.313 + fclose(dictFile);
1.314 +
1.315 + dictFile = nullptr;
1.316 + }
1.317 +
1.318 + if (!failed && treeFile) {
1.319 + // Make sure every start entry has a corresponding stop value.
1.320 + // We temporary enable logging for this. Stop doesn't need any extra data,
1.321 + // so is safe to do, even when we encountered OOM.
1.322 + enabled = true;
1.323 + while (stack.size() > 0)
1.324 + stopEvent();
1.325 + enabled = false;
1.326 + }
1.327 +
1.328 + if (!failed && !flush()) {
1.329 + fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
1.330 + enabled = false;
1.331 + failed = true;
1.332 + }
1.333 +
1.334 + if (treeFile) {
1.335 + fclose(treeFile);
1.336 + treeFile = nullptr;
1.337 + }
1.338 +
1.339 + if (eventFile) {
1.340 + fclose(eventFile);
1.341 + eventFile = nullptr;
1.342 + }
1.343 +}
1.344 +
1.345 +uint32_t
1.346 +TraceLogger::createTextId(const char *text)
1.347 +{
1.348 + assertNoQuotes(text);
1.349 +
1.350 + PointerHashMap::AddPtr p = pointerMap.lookupForAdd((const void *)text);
1.351 + if (p)
1.352 + return p->value();
1.353 +
1.354 + uint32_t textId = nextTextId++;
1.355 + if (!pointerMap.add(p, text, textId))
1.356 + return TraceLogger::TL_Error;
1.357 +
1.358 + int written;
1.359 + if (textId > 0)
1.360 + written = fprintf(dictFile, ",\n\"%s\"", text);
1.361 + else
1.362 + written = fprintf(dictFile, "\"%s\"", text);
1.363 +
1.364 + if (written < 0)
1.365 + return TraceLogger::TL_Error;
1.366 +
1.367 + return textId;
1.368 +}
1.369 +
1.370 +uint32_t
1.371 +TraceLogger::createTextId(JSScript *script)
1.372 +{
1.373 + assertNoQuotes(script->filename());
1.374 +
1.375 + PointerHashMap::AddPtr p = pointerMap.lookupForAdd(script);
1.376 + if (p)
1.377 + return p->value();
1.378 +
1.379 + uint32_t textId = nextTextId++;
1.380 + if (!pointerMap.add(p, script, textId))
1.381 + return TraceLogger::TL_Error;
1.382 +
1.383 + int written;
1.384 + if (textId > 0) {
1.385 + written = fprintf(dictFile, ",\n\"script %s:%d:%d\"", script->filename(),
1.386 + script->lineno(), script->column());
1.387 + } else {
1.388 + written = fprintf(dictFile, "\"script %s:%d:%d\"", script->filename(),
1.389 + script->lineno(), script->column());
1.390 + }
1.391 +
1.392 + if (written < 0)
1.393 + return TraceLogger::TL_Error;
1.394 +
1.395 + return textId;
1.396 +}
1.397 +
1.398 +uint32_t
1.399 +TraceLogger::createTextId(const JS::ReadOnlyCompileOptions &compileOptions)
1.400 +{
1.401 + assertNoQuotes(compileOptions.filename());
1.402 +
1.403 + PointerHashMap::AddPtr p = pointerMap.lookupForAdd(&compileOptions);
1.404 + if (p)
1.405 + return p->value();
1.406 +
1.407 + uint32_t textId = nextTextId++;
1.408 + if (!pointerMap.add(p, &compileOptions, textId))
1.409 + return TraceLogger::TL_Error;
1.410 +
1.411 + int written;
1.412 + if (textId > 0) {
1.413 + written = fprintf(dictFile, ",\n\"script %s:%d:%d\"", compileOptions.filename(),
1.414 + compileOptions.lineno, compileOptions.column);
1.415 + } else {
1.416 + written = fprintf(dictFile, "\"script %s:%d:%d\"", compileOptions.filename(),
1.417 + compileOptions.lineno, compileOptions.column);
1.418 + }
1.419 +
1.420 + if (written < 0)
1.421 + return TraceLogger::TL_Error;
1.422 +
1.423 + return textId;
1.424 +}
1.425 +
1.426 +void
1.427 +TraceLogger::logTimestamp(uint32_t id)
1.428 +{
1.429 + if (!enabled)
1.430 + return;
1.431 +
1.432 + if (!events.ensureSpaceBeforeAdd()) {
1.433 + fprintf(stderr, "TraceLogging: Disabled a tracelogger due to OOM.\n");
1.434 + enabled = false;
1.435 + return;
1.436 + }
1.437 +
1.438 + uint64_t time = rdtsc() - traceLoggers.startupTime;
1.439 +
1.440 + EventEntry &entry = events.pushUninitialized();
1.441 + entry.time = time;
1.442 + entry.textId = id;
1.443 +}
1.444 +
1.445 +void
1.446 +TraceLogger::entryToBigEndian(TreeEntry *entry)
1.447 +{
1.448 + entry->start_ = htobe64(entry->start_);
1.449 + entry->stop_ = htobe64(entry->stop_);
1.450 + entry->u.value_ = htobe32((entry->u.s.textId_ << 1) + entry->u.s.hasChildren_);
1.451 + entry->nextId_ = htobe32(entry->nextId_);
1.452 +}
1.453 +
1.454 +void
1.455 +TraceLogger::entryToSystemEndian(TreeEntry *entry)
1.456 +{
1.457 + entry->start_ = be64toh(entry->start_);
1.458 + entry->stop_ = be64toh(entry->stop_);
1.459 +
1.460 + uint32_t data = be32toh(entry->u.value_);
1.461 + entry->u.s.textId_ = data >> 1;
1.462 + entry->u.s.hasChildren_ = data & 0x1;
1.463 +
1.464 + entry->nextId_ = be32toh(entry->nextId_);
1.465 +}
1.466 +
1.467 +bool
1.468 +TraceLogger::getTreeEntry(uint32_t treeId, TreeEntry *entry)
1.469 +{
1.470 + // Entry is still in memory
1.471 + if (treeId >= treeOffset) {
1.472 + *entry = tree[treeId];
1.473 + return true;
1.474 + }
1.475 +
1.476 + int success = fseek(treeFile, treeId * sizeof(TreeEntry), SEEK_SET);
1.477 + if (success != 0)
1.478 + return false;
1.479 +
1.480 + size_t itemsRead = fread((void *)entry, sizeof(TreeEntry), 1, treeFile);
1.481 + if (itemsRead < 1)
1.482 + return false;
1.483 +
1.484 + entryToSystemEndian(entry);
1.485 + return true;
1.486 +}
1.487 +
1.488 +bool
1.489 +TraceLogger::saveTreeEntry(uint32_t treeId, TreeEntry *entry)
1.490 +{
1.491 + int success = fseek(treeFile, treeId * sizeof(TreeEntry), SEEK_SET);
1.492 + if (success != 0)
1.493 + return false;
1.494 +
1.495 + entryToBigEndian(entry);
1.496 +
1.497 + size_t itemsWritten = fwrite(entry, sizeof(TreeEntry), 1, treeFile);
1.498 + if (itemsWritten < 1)
1.499 + return false;
1.500 +
1.501 + return true;
1.502 +}
1.503 +
1.504 +bool
1.505 +TraceLogger::updateHasChildren(uint32_t treeId, bool hasChildren)
1.506 +{
1.507 + if (treeId < treeOffset) {
1.508 + TreeEntry entry;
1.509 + if (!getTreeEntry(treeId, &entry))
1.510 + return false;
1.511 + entry.setHasChildren(hasChildren);
1.512 + if (!saveTreeEntry(treeId, &entry))
1.513 + return false;
1.514 + return true;
1.515 + }
1.516 +
1.517 + tree[treeId - treeOffset].setHasChildren(hasChildren);
1.518 + return true;
1.519 +}
1.520 +
1.521 +bool
1.522 +TraceLogger::updateNextId(uint32_t treeId, uint32_t nextId)
1.523 +{
1.524 + if (treeId < treeOffset) {
1.525 + TreeEntry entry;
1.526 + if (!getTreeEntry(treeId, &entry))
1.527 + return false;
1.528 + entry.setNextId(nextId);
1.529 + if (!saveTreeEntry(treeId, &entry))
1.530 + return false;
1.531 + return true;
1.532 + }
1.533 +
1.534 + tree[treeId - treeOffset].setNextId(nextId);
1.535 + return true;
1.536 +}
1.537 +
1.538 +bool
1.539 +TraceLogger::updateStop(uint32_t treeId, uint64_t timestamp)
1.540 +{
1.541 + if (treeId < treeOffset) {
1.542 + TreeEntry entry;
1.543 + if (!getTreeEntry(treeId, &entry))
1.544 + return false;
1.545 + entry.setStop(timestamp);
1.546 + if (!saveTreeEntry(treeId, &entry))
1.547 + return false;
1.548 + return true;
1.549 + }
1.550 +
1.551 + tree[treeId - treeOffset].setStop(timestamp);
1.552 + return true;
1.553 +}
1.554 +
1.555 +void
1.556 +TraceLogger::startEvent(uint32_t id)
1.557 +{
1.558 + if (failed)
1.559 + return;
1.560 +
1.561 + if (!stack.ensureSpaceBeforeAdd()) {
1.562 + fprintf(stderr, "TraceLogging: Failed to allocate space to keep track of the stack.\n");
1.563 + enabled = false;
1.564 + failed = true;
1.565 + return;
1.566 + }
1.567 +
1.568 + if (!enabled) {
1.569 + StackEntry &stackEntry = stack.pushUninitialized();
1.570 + stackEntry.setTreeId(tree.currentId() + treeOffset);
1.571 + stackEntry.setLastChildId(0);
1.572 + stackEntry.setTextId(id);
1.573 + stackEntry.setActive(false);
1.574 + return;
1.575 + }
1.576 +
1.577 + if (!tree.ensureSpaceBeforeAdd()) {
1.578 + uint64_t start = rdtsc() - traceLoggers.startupTime;
1.579 + if (!flush()) {
1.580 + fprintf(stderr, "TraceLogging: Couldn't write the data to disk.\n");
1.581 + enabled = false;
1.582 + failed = true;
1.583 + return;
1.584 + }
1.585 +
1.586 + // Log the time it took to flush the events as being from the
1.587 + // Tracelogger.
1.588 + if (!startEvent(TraceLogger::TL, start)) {
1.589 + fprintf(stderr, "TraceLogging: Failed to start an event.\n");
1.590 + enabled = false;
1.591 + failed = true;
1.592 + return;
1.593 + }
1.594 + stopEvent();
1.595 + }
1.596 +
1.597 + uint64_t start = rdtsc() - traceLoggers.startupTime;
1.598 + if (!startEvent(id, start)) {
1.599 + fprintf(stderr, "TraceLogging: Failed to start an event.\n");
1.600 + enabled = false;
1.601 + failed = true;
1.602 + return;
1.603 + }
1.604 +}
1.605 +
1.606 +TraceLogger::StackEntry &
1.607 +TraceLogger::getActiveAncestor()
1.608 +{
1.609 + uint32_t parentId = stack.currentId();
1.610 + while (!stack[parentId].active())
1.611 + parentId--;
1.612 + return stack[parentId];
1.613 +}
1.614 +
1.615 +bool
1.616 +TraceLogger::startEvent(uint32_t id, uint64_t timestamp)
1.617 +{
1.618 + // When a textId is disabled, a stack entry still needs to be pushed,
1.619 + // together with an annotation that nothing needs to get done when receiving
1.620 + // the stop event.
1.621 + if (!traceLoggers.isTextIdEnabled(id)) {
1.622 + StackEntry &stackEntry = stack.pushUninitialized();
1.623 + stackEntry.setActive(false);
1.624 + return true;
1.625 + }
1.626 +
1.627 + // Patch up the tree to be correct. There are two scenarios:
1.628 + // 1) Parent has no children yet. So update parent to include children.
1.629 + // 2) Parent has already children. Update last child to link to the new
1.630 + // child.
1.631 + StackEntry &parent = getActiveAncestor();
1.632 +#ifdef DEBUG
1.633 + TreeEntry entry;
1.634 + if (!getTreeEntry(parent.treeId(), &entry))
1.635 + return false;
1.636 +#endif
1.637 +
1.638 + if (parent.lastChildId() == 0) {
1.639 + MOZ_ASSERT(!entry.hasChildren());
1.640 + MOZ_ASSERT(parent.treeId() == tree.currentId() + treeOffset);
1.641 +
1.642 + if (!updateHasChildren(parent.treeId()))
1.643 + return false;
1.644 + } else {
1.645 + MOZ_ASSERT(entry.hasChildren());
1.646 +
1.647 + if (!updateNextId(parent.lastChildId(), tree.nextId() + treeOffset))
1.648 + return false;
1.649 + }
1.650 +
1.651 + // Add a new tree entry.
1.652 + TreeEntry &treeEntry = tree.pushUninitialized();
1.653 + treeEntry.setStart(timestamp);
1.654 + treeEntry.setStop(0);
1.655 + treeEntry.setTextId(id);
1.656 + treeEntry.setHasChildren(false);
1.657 + treeEntry.setNextId(0);
1.658 +
1.659 + // Add a new stack entry.
1.660 + StackEntry &stackEntry = stack.pushUninitialized();
1.661 + stackEntry.setTreeId(tree.currentId() + treeOffset);
1.662 + stackEntry.setLastChildId(0);
1.663 + stackEntry.setActive(true);
1.664 +
1.665 + // Set the last child of the parent to this newly added entry.
1.666 + parent.setLastChildId(tree.currentId() + treeOffset);
1.667 +
1.668 + return true;
1.669 +}
1.670 +
1.671 +void
1.672 +TraceLogger::stopEvent(uint32_t id)
1.673 +{
1.674 +#ifdef DEBUG
1.675 + TreeEntry entry;
1.676 + MOZ_ASSERT_IF(stack.current().active(), getTreeEntry(stack.current().treeId(), &entry));
1.677 + MOZ_ASSERT_IF(stack.current().active(), entry.textId() == id);
1.678 +#endif
1.679 + stopEvent();
1.680 +}
1.681 +
1.682 +void
1.683 +TraceLogger::stopEvent()
1.684 +{
1.685 + if (enabled && stack.current().active()) {
1.686 + uint64_t stop = rdtsc() - traceLoggers.startupTime;
1.687 + if (!updateStop(stack.current().treeId(), stop)) {
1.688 + fprintf(stderr, "TraceLogging: Failed to stop an event.\n");
1.689 + enabled = false;
1.690 + failed = true;
1.691 + return;
1.692 + }
1.693 + }
1.694 + stack.pop();
1.695 +}
1.696 +
1.697 +TraceLogging::TraceLogging()
1.698 +{
1.699 + initialized = false;
1.700 + enabled = false;
1.701 + mainThreadEnabled = true;
1.702 + offThreadEnabled = true;
1.703 + loggerId = 0;
1.704 +
1.705 +#ifdef JS_THREADSAFE
1.706 + lock = PR_NewLock();
1.707 + if (!lock)
1.708 + MOZ_CRASH();
1.709 +#endif // JS_THREADSAFE
1.710 +}
1.711 +
1.712 +TraceLogging::~TraceLogging()
1.713 +{
1.714 + if (out) {
1.715 + fprintf(out, "]");
1.716 + fclose(out);
1.717 + out = nullptr;
1.718 + }
1.719 +
1.720 + for (size_t i = 0; i < mainThreadLoggers.length(); i++)
1.721 + delete mainThreadLoggers[i];
1.722 +
1.723 + mainThreadLoggers.clear();
1.724 +
1.725 +#ifdef JS_THREADSAFE
1.726 + if (threadLoggers.initialized()) {
1.727 + for (ThreadLoggerHashMap::Range r = threadLoggers.all(); !r.empty(); r.popFront())
1.728 + delete r.front().value();
1.729 +
1.730 + threadLoggers.finish();
1.731 + }
1.732 +
1.733 + if (lock) {
1.734 + PR_DestroyLock(lock);
1.735 + lock = nullptr;
1.736 + }
1.737 +#endif // JS_THREADSAFE
1.738 +
1.739 + enabled = false;
1.740 +}
1.741 +
1.742 +static bool
1.743 +ContainsFlag(const char *str, const char *flag)
1.744 +{
1.745 + size_t flaglen = strlen(flag);
1.746 + const char *index = strstr(str, flag);
1.747 + while (index) {
1.748 + if ((index == str || index[-1] == ',') && (index[flaglen] == 0 || index[flaglen] == ','))
1.749 + return true;
1.750 + index = strstr(index + flaglen, flag);
1.751 + }
1.752 + return false;
1.753 +}
1.754 +
1.755 +bool
1.756 +TraceLogging::lazyInit()
1.757 +{
1.758 + if (initialized)
1.759 + return enabled;
1.760 +
1.761 + initialized = true;
1.762 +
1.763 + out = fopen(TRACE_LOG_DIR "tl-data.json", "w");
1.764 + if (!out)
1.765 + return false;
1.766 + fprintf(out, "[");
1.767 +
1.768 +#ifdef JS_THREADSAFE
1.769 + if (!threadLoggers.init())
1.770 + return false;
1.771 +#endif // JS_THREADSAFE
1.772 +
1.773 + const char *env = getenv("TLLOG");
1.774 + if (!env)
1.775 + env = "";
1.776 +
1.777 + if (strstr(env, "help")) {
1.778 + fflush(nullptr);
1.779 + printf(
1.780 + "\n"
1.781 + "usage: TLLOG=option,option,option,... where options can be:\n"
1.782 + "\n"
1.783 + "Collections:\n"
1.784 + " Default Output all default\n"
1.785 + " IonCompiler Output all information about compilation\n"
1.786 + "\n"
1.787 + "Specific log items:\n"
1.788 + );
1.789 + for (uint32_t i = 1; i < TraceLogger::LAST; i++) {
1.790 + printf(" %s\n", text[i]);
1.791 + }
1.792 + printf("\n");
1.793 + exit(0);
1.794 + /*NOTREACHED*/
1.795 + }
1.796 +
1.797 + for (uint32_t i = 1; i < TraceLogger::LAST; i++)
1.798 + enabledTextIds[i] = ContainsFlag(env, text[i]);
1.799 +
1.800 + enabledTextIds[TraceLogger::TL_Error] = true;
1.801 + enabledTextIds[TraceLogger::TL] = true;
1.802 +
1.803 + if (ContainsFlag(env, "Default") || strlen(env) == 0) {
1.804 + enabledTextIds[TraceLogger::Bailout] = true;
1.805 + enabledTextIds[TraceLogger::Baseline] = true;
1.806 + enabledTextIds[TraceLogger::BaselineCompilation] = true;
1.807 + enabledTextIds[TraceLogger::GC] = true;
1.808 + enabledTextIds[TraceLogger::GCAllocation] = true;
1.809 + enabledTextIds[TraceLogger::GCSweeping] = true;
1.810 + enabledTextIds[TraceLogger::Interpreter] = true;
1.811 + enabledTextIds[TraceLogger::IonCompilation] = true;
1.812 + enabledTextIds[TraceLogger::IonLinking] = true;
1.813 + enabledTextIds[TraceLogger::IonMonkey] = true;
1.814 + enabledTextIds[TraceLogger::MinorGC] = true;
1.815 + enabledTextIds[TraceLogger::ParserCompileFunction] = true;
1.816 + enabledTextIds[TraceLogger::ParserCompileLazy] = true;
1.817 + enabledTextIds[TraceLogger::ParserCompileScript] = true;
1.818 + enabledTextIds[TraceLogger::YarrCompile] = true;
1.819 + enabledTextIds[TraceLogger::YarrInterpret] = true;
1.820 + enabledTextIds[TraceLogger::YarrJIT] = true;
1.821 + }
1.822 +
1.823 + if (ContainsFlag(env, "IonCompiler") || strlen(env) == 0) {
1.824 + enabledTextIds[TraceLogger::IonCompilation] = true;
1.825 + enabledTextIds[TraceLogger::IonLinking] = true;
1.826 + enabledTextIds[TraceLogger::SplitCriticalEdges] = true;
1.827 + enabledTextIds[TraceLogger::RenumberBlocks] = true;
1.828 + enabledTextIds[TraceLogger::DominatorTree] = true;
1.829 + enabledTextIds[TraceLogger::PhiAnalysis] = true;
1.830 + enabledTextIds[TraceLogger::ApplyTypes] = true;
1.831 + enabledTextIds[TraceLogger::ParallelSafetyAnalysis] = true;
1.832 + enabledTextIds[TraceLogger::AliasAnalysis] = true;
1.833 + enabledTextIds[TraceLogger::GVN] = true;
1.834 + enabledTextIds[TraceLogger::UCE] = true;
1.835 + enabledTextIds[TraceLogger::LICM] = true;
1.836 + enabledTextIds[TraceLogger::RangeAnalysis] = true;
1.837 + enabledTextIds[TraceLogger::EffectiveAddressAnalysis] = true;
1.838 + enabledTextIds[TraceLogger::EliminateDeadCode] = true;
1.839 + enabledTextIds[TraceLogger::EdgeCaseAnalysis] = true;
1.840 + enabledTextIds[TraceLogger::EliminateRedundantChecks] = true;
1.841 + }
1.842 +
1.843 + const char *options = getenv("TLOPTIONS");
1.844 + if (options) {
1.845 + if (strstr(options, "help")) {
1.846 + fflush(nullptr);
1.847 + printf(
1.848 + "\n"
1.849 + "usage: TLOPTIONS=option,option,option,... where options can be:\n"
1.850 + "\n"
1.851 + " DisableMainThread Don't start logging the mainThread automatically.\n"
1.852 + " DisableOffThread Don't start logging the off mainThread automatically.\n"
1.853 + );
1.854 + printf("\n");
1.855 + exit(0);
1.856 + /*NOTREACHED*/
1.857 + }
1.858 +
1.859 + if (strstr(options, "DisableMainThread"))
1.860 + mainThreadEnabled = false;
1.861 + if (strstr(options, "DisableOffThread"))
1.862 + offThreadEnabled = false;
1.863 + }
1.864 +
1.865 + startupTime = rdtsc();
1.866 + enabled = true;
1.867 + return true;
1.868 +}
1.869 +
1.870 +TraceLogger *
1.871 +js::TraceLoggerForMainThread(jit::CompileRuntime *runtime)
1.872 +{
1.873 + return traceLoggers.forMainThread(runtime);
1.874 +}
1.875 +
1.876 +TraceLogger *
1.877 +TraceLogging::forMainThread(jit::CompileRuntime *runtime)
1.878 +{
1.879 + return forMainThread(runtime->mainThread());
1.880 +}
1.881 +
1.882 +TraceLogger *
1.883 +js::TraceLoggerForMainThread(JSRuntime *runtime)
1.884 +{
1.885 + return traceLoggers.forMainThread(runtime);
1.886 +}
1.887 +
1.888 +TraceLogger *
1.889 +TraceLogging::forMainThread(JSRuntime *runtime)
1.890 +{
1.891 + return forMainThread(&runtime->mainThread);
1.892 +}
1.893 +
1.894 +TraceLogger *
1.895 +TraceLogging::forMainThread(PerThreadData *mainThread)
1.896 +{
1.897 + if (!mainThread->traceLogger) {
1.898 + AutoTraceLoggingLock lock(this);
1.899 +
1.900 + if (!lazyInit())
1.901 + return nullptr;
1.902 +
1.903 + TraceLogger *logger = create();
1.904 + mainThread->traceLogger = logger;
1.905 +
1.906 + if (!mainThreadLoggers.append(logger))
1.907 + return nullptr;
1.908 +
1.909 + if (!mainThreadEnabled)
1.910 + logger->disable();
1.911 + }
1.912 +
1.913 + return mainThread->traceLogger;
1.914 +}
1.915 +
1.916 +TraceLogger *
1.917 +js::TraceLoggerForCurrentThread()
1.918 +{
1.919 +#ifdef JS_THREADSAFE
1.920 + PRThread *thread = PR_GetCurrentThread();
1.921 + return traceLoggers.forThread(thread);
1.922 +#else
1.923 + MOZ_ASSUME_UNREACHABLE("No threads supported. Use TraceLoggerForMainThread for the main thread.");
1.924 +#endif // JS_THREADSAFE
1.925 +}
1.926 +
1.927 +#ifdef JS_THREADSAFE
1.928 +TraceLogger *
1.929 +TraceLogging::forThread(PRThread *thread)
1.930 +{
1.931 + AutoTraceLoggingLock lock(this);
1.932 +
1.933 + if (!lazyInit())
1.934 + return nullptr;
1.935 +
1.936 + ThreadLoggerHashMap::AddPtr p = threadLoggers.lookupForAdd(thread);
1.937 + if (p)
1.938 + return p->value();
1.939 +
1.940 + TraceLogger *logger = create();
1.941 + if (!logger)
1.942 + return nullptr;
1.943 +
1.944 + if (!threadLoggers.add(p, thread, logger)) {
1.945 + delete logger;
1.946 + return nullptr;
1.947 + }
1.948 +
1.949 + if (!offThreadEnabled)
1.950 + logger->disable();
1.951 +
1.952 + return logger;
1.953 +}
1.954 +#endif // JS_THREADSAFE
1.955 +
1.956 +TraceLogger *
1.957 +TraceLogging::create()
1.958 +{
1.959 + if (loggerId > 999) {
1.960 + fprintf(stderr, "TraceLogging: Can't create more than 999 different loggers.");
1.961 + return nullptr;
1.962 + }
1.963 +
1.964 + if (loggerId > 0) {
1.965 + int written = fprintf(out, ",\n");
1.966 + if (written < 0)
1.967 + fprintf(stderr, "TraceLogging: Error while writing.\n");
1.968 + }
1.969 +
1.970 + loggerId++;
1.971 +
1.972 + int written = fprintf(out, "{\"tree\":\"tl-tree.%d.tl\", \"events\":\"tl-event.%d.tl\", \"dict\":\"tl-dict.%d.json\", \"treeFormat\":\"64,64,31,1,32\"}",
1.973 + loggerId, loggerId, loggerId);
1.974 + if (written < 0)
1.975 + fprintf(stderr, "TraceLogging: Error while writing.\n");
1.976 +
1.977 +
1.978 + TraceLogger *logger = new TraceLogger();
1.979 + if (!logger)
1.980 + return nullptr;
1.981 +
1.982 + if (!logger->init(loggerId)) {
1.983 + delete logger;
1.984 + return nullptr;
1.985 + }
1.986 +
1.987 + return logger;
1.988 +}
1.989 +
1.990 +bool
1.991 +js::TraceLogTextIdEnabled(uint32_t textId)
1.992 +{
1.993 + return traceLoggers.isTextIdEnabled(textId);
1.994 +}
