Bug 944392 - Tracelogging: Land version 0.2, r=till,bbouvier

This commit is contained in:
Hannes Verschore 2014-04-09 14:20:39 +02:00
parent 42bbba90be
commit 28d23c2884
23 changed files with 1274 additions and 521 deletions

View File

@ -6,15 +6,13 @@
#include "TraceLogging.h"
#include <cstdarg>
#include <cstdio>
#include <cstdlib>
#include <stdint.h>
#include <string.h>
#include <unistd.h>
#include "jsapi.h"
#include "jsscript.h"
#include "vm/Runtime.h"
using namespace js;
#ifndef TRACE_LOG_DIR
@ -64,239 +62,465 @@ rdtsc(void)
}
#endif
const char* const TraceLogging::typeName[] = {
"1,s", // start script
"0,s", // stop script
"1,c", // start ion compilation
"0,c", // stop ion compilation
"1,r", // start regexp JIT execution
"0,r", // stop regexp JIT execution
"1,G", // start major GC
"0,G", // stop major GC
"1,g", // start minor GC
"0,g", // stop minor GC
"1,gS", // start GC sweeping
"0,gS", // stop GC sweeping
"1,gA", // start GC allocating
"0,gA", // stop GC allocating
"1,ps", // start script parsing
"0,ps", // stop script parsing
"1,pl", // start lazy parsing
"0,pl", // stop lazy parsing
"1,pf", // start Function parsing
"0,pf", // stop Function parsing
"e,i", // engine interpreter
"e,b", // engine baseline
"e,o" // engine ionmonkey
};
TraceLogging* TraceLogging::loggers[] = {nullptr, nullptr, nullptr};
bool TraceLogging::atexitSet = false;
uint64_t TraceLogging::startupTime = 0;
TraceLogging traceLoggers;
TraceLogging::TraceLogging(Logger id)
: nextTextId(1),
entries(nullptr),
curEntry(0),
numEntries(1000000),
fileno(0),
out(nullptr),
id(id)
// The text that will get logged for eagerly created logged text.
// When adding/removing something here, you must update the enum
// Tracelogger::TextId in TraceLogging.h too.
const char* const text[] = {
"TraceLogger failed to process text",
"Bailout",
"Baseline",
"GC",
"GCAllocating",
"GCSweeping",
"Interpreter",
"Invalidation",
"IonCompile",
"IonLink",
"IonMonkey",
"MinorGC",
"ParserCompileFunction",
"ParserCompileLazy",
"ParserCompileScript",
"TraceLogger",
"YarrCompile",
"YarrInterpret",
"YarrJIT"
};
TraceLogger::TraceLogger()
: enabled(false),
nextTextId(0),
top(nullptr)
{ }
bool
TraceLogger::init(uint32_t loggerId)
{
textMap.init();
if (!pointerMap.init())
return false;
if (!tree.init())
return false;
if (!stack.init())
return false;
if (!events.init())
return false;
JS_ASSERT(loggerId <= 999);
char dictFilename[sizeof TRACE_LOG_DIR "tl-dict.100.json"];
sprintf(dictFilename, TRACE_LOG_DIR "tl-dict.%d.json", loggerId);
dictFile = fopen(dictFilename, "w");
if (!dictFile)
return false;
char treeFilename[sizeof TRACE_LOG_DIR "tl-tree.100.tl"];
sprintf(treeFilename, TRACE_LOG_DIR "tl-tree.%d.tl", loggerId);
treeFile = fopen(treeFilename, "wb");
if (!treeFile) {
fclose(dictFile);
dictFile = nullptr;
return false;
}
char eventFilename[sizeof TRACE_LOG_DIR "tl-event.100.tl"];
sprintf(eventFilename, TRACE_LOG_DIR "tl-event.%d.tl", loggerId);
eventFile = fopen(eventFilename, "wb");
if (!eventFile) {
fclose(dictFile);
fclose(treeFile);
dictFile = nullptr;
treeFile = nullptr;
return false;
}
uint64_t start = rdtsc() - traceLoggers.startupTime;
TreeEntry &treeEntry = tree.pushUninitialized();
treeEntry.start = start;
treeEntry.stop = 0;
treeEntry.u.s.textId = 0;
treeEntry.u.s.hasChildren = false;
treeEntry.nextId = 0;
StackEntry &stackEntry = stack.pushUninitialized();
stackEntry.treeId = 0;
stackEntry.lastChildId = 0;
int written = fprintf(dictFile, "[");
if (written < 0)
fprintf(stderr, "TraceLogging: Error while writing.\n");
// Eagerly create the default textIds, to match their Tracelogger::TextId.
for (uint32_t i = 0; i < LAST; i++) {
uint32_t textId = createTextId(text[i]);
JS_ASSERT(textId == i);
}
enabled = true;
return true;
}
TraceLogger::~TraceLogger()
{
// Write dictionary to disk
if (dictFile) {
int written = fprintf(dictFile, "]");
if (written < 0)
fprintf(stderr, "TraceLogging: Error while writing.\n");
fclose(dictFile);
dictFile = nullptr;
}
// Write tree of logged events to disk.
if (treeFile) {
// Make sure every start entry has a corresponding stop value.
// We temporary enable logging for this. Stop doesn't need any extra data,
// so is safe to do, even when we encountered OOM.
enabled = true;
while (stack.size() > 0)
stopEvent();
enabled = false;
// Format data in big endian.
for (uint32_t i = 0; i < tree.size(); i++) {
tree[i].start = htobe64(tree[i].start);
tree[i].stop = htobe64(tree[i].stop);
tree[i].u.value = htobe32((tree[i].u.s.textId << 1) + tree[i].u.s.hasChildren);
tree[i].nextId = htobe32(tree[i].nextId);
}
size_t bytesWritten = fwrite(tree.data(), sizeof(TreeEntry), tree.size(), treeFile);
if (bytesWritten < tree.size())
fprintf(stderr, "TraceLogging: Couldn't write the full tree to disk.\n");
tree.clear();
fclose(treeFile);
treeFile = nullptr;
}
// Write details for all log entries to disk.
if (eventFile) {
// Format data in big endian
for (uint32_t i = 0; i < events.size(); i++) {
events[i].time = htobe64(events[i].time);
events[i].textId = htobe64(events[i].textId);
}
size_t bytesWritten = fwrite(events.data(), sizeof(EventEntry), events.size(), eventFile);
if (bytesWritten < events.size())
fprintf(stderr, "TraceLogging: Couldn't write all event entries to disk.\n");
events.clear();
fclose(eventFile);
eventFile = nullptr;
}
}
uint32_t
TraceLogger::createTextId(const char *text)
{
assertNoQuotes(text);
PointerHashMap::AddPtr p = pointerMap.lookupForAdd((const void *)text);
if (p)
return p->value();
uint32_t textId = nextTextId++;
if (!pointerMap.add(p, text, textId))
return TraceLogger::TL_Error;
int written;
if (textId > 0)
written = fprintf(dictFile, ",\n\"%s\"", text);
else
written = fprintf(dictFile, "\"%s\"", text);
if (written < 0)
return TraceLogger::TL_Error;
return textId;
}
uint32_t
TraceLogger::createTextId(JSScript *script)
{
assertNoQuotes(script->filename());
PointerHashMap::AddPtr p = pointerMap.lookupForAdd(script);
if (p)
return p->value();
uint32_t textId = nextTextId++;
if (!pointerMap.add(p, script, textId))
return TraceLogger::TL_Error;
int written;
if (textId > 0) {
written = fprintf(dictFile, ",\n\"script %s:%d:%d\"", script->filename(),
script->lineno(), script->column());
} else {
written = fprintf(dictFile, "\"script %s:%d:%d\"", script->filename(),
script->lineno(), script->column());
}
if (written < 0)
return TraceLogger::TL_Error;
return textId;
}
uint32_t
TraceLogger::createTextId(const JS::ReadOnlyCompileOptions &compileOptions)
{
assertNoQuotes(compileOptions.filename());
PointerHashMap::AddPtr p = pointerMap.lookupForAdd(&compileOptions);
if (p)
return p->value();
uint32_t textId = nextTextId++;
if (!pointerMap.add(p, &compileOptions, textId))
return TraceLogger::TL_Error;
int written;
if (textId > 0) {
written = fprintf(dictFile, ",\n\"script %s:%d:%d\"", compileOptions.filename(),
compileOptions.lineno, compileOptions.column);
} else {
written = fprintf(dictFile, "\"script %s:%d:%d\"", compileOptions.filename(),
compileOptions.lineno, compileOptions.column);
}
if (written < 0)
return TraceLogger::TL_Error;
return textId;
}
void
TraceLogger::logTimestamp(uint32_t id)
{
if (!enabled)
return;
if (!events.ensureSpaceBeforeAdd()) {
fprintf(stderr, "TraceLogging: Disabled a tracelogger due to OOM.\n");
enabled = false;
return;
}
uint64_t time = rdtsc() - traceLoggers.startupTime;
EventEntry &entry = events.pushUninitialized();
entry.time = time;
entry.textId = id;
}
void
TraceLogger::startEvent(uint32_t id)
{
if (!enabled)
return;
if (!tree.ensureSpaceBeforeAdd() || !stack.ensureSpaceBeforeAdd()) {
fprintf(stderr, "TraceLogging: Disabled a tracelogger due to OOM.\n");
enabled = false;
return;
}
uint64_t start = rdtsc() - traceLoggers.startupTime;
// 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 = stack.current();
if (parent.lastChildId == 0) {
JS_ASSERT(tree[parent.treeId].u.s.hasChildren == 0);
JS_ASSERT(parent.treeId == tree.currentId());
tree[parent.treeId].u.s.hasChildren = 1;
} else {
JS_ASSERT(tree[parent.treeId].u.s.hasChildren == 1);
tree[parent.lastChildId].nextId = tree.nextId();
}
// Add a new tree entry.
TreeEntry &treeEntry = tree.pushUninitialized();
treeEntry.start = start;
treeEntry.stop = 0;
treeEntry.u.s.textId = id;
treeEntry.u.s.hasChildren = false;
treeEntry.nextId = 0;
// Add a new stack entry.
StackEntry &stackEntry = stack.pushUninitialized();
stackEntry.treeId = tree.currentId();
stackEntry.lastChildId = 0;
// Set the last child of the parent to this newly added entry.
parent.lastChildId = tree.currentId();
}
void
TraceLogger::stopEvent(uint32_t id)
{
MOZ_ASSERT_IF(enabled, tree[stack.current().treeId].u.s.textId == id);
stopEvent();
}
void
TraceLogger::stopEvent()
{
if (!enabled)
return;
uint64_t stop = rdtsc() - traceLoggers.startupTime;
tree[stack.current().treeId].stop = stop;
stack.pop();
}
TraceLogging::TraceLogging()
{
initialized = false;
enabled = false;
loggerId = 0;
#ifdef JS_THREADSAFE
lock = PR_NewLock();
if (!lock)
MOZ_CRASH();
#endif
}
TraceLogging::~TraceLogging()
{
if (entries) {
flush();
js_free(entries);
entries = nullptr;
}
if (out) {
fprintf(out, "]");
fclose(out);
out = nullptr;
}
}
void
TraceLogging::grow()
{
Entry* nentries = (Entry*) js_realloc(entries, numEntries*2*sizeof(Entry));
// Allocating a bigger array failed.
// Keep using the current storage, but remove all entries by flushing them.
if (!nentries) {
flush();
return;
}
entries = nentries;
numEntries *= 2;
}
void
TraceLogging::log(Type type, const char* text /* = nullptr */, unsigned int number /* = 0 */)
{
uint64_t now = rdtsc() - startupTime;
// Create array containing the entries if not existing.
if (!entries) {
entries = (Entry*) js_malloc(numEntries*sizeof(Entry));
if (!entries)
return;
}
uint32_t textId = 0;
char *text_ = nullptr;
if (text) {
TextHashMap::AddPtr p = textMap.lookupForAdd(text);
if (!p) {
// Copy the text, because original could already be freed before writing the log file.
text_ = strdup(text);
if (!text_)
return;
textId = nextTextId++;
if (!textMap.add(p, text, textId))
return;
} else {
textId = p->value();
}
}
entries[curEntry++] = Entry(now, text_, textId, number, type);
// Increase length when not enough place in the array
if (curEntry >= numEntries)
grow();
}
void
TraceLogging::log(Type type, const JS::ReadOnlyCompileOptions &options)
{
this->log(type, options.filename(), options.lineno);
}
void
TraceLogging::log(Type type, JSScript* script)
{
this->log(type, script->filename(), script->lineno());
}
void
TraceLogging::log(const char* log)
{
this->log(INFO, log, 0);
}
void
TraceLogging::flush()
{
// Open the logging file, when not opened yet.
if (!out) {
switch(id) {
case DEFAULT:
out = fopen(TRACE_LOG_DIR "tracelogging.log", "w");
break;
case ION_BACKGROUND_COMPILER:
out = fopen(TRACE_LOG_DIR "tracelogging-compile.log", "w");
break;
case GC_BACKGROUND:
out = fopen(TRACE_LOG_DIR "tracelogging-gc.log", "w");
break;
default:
MOZ_ASSUME_UNREACHABLE("Bad trigger");
return;
}
}
// Print all log entries into the file
for (unsigned int i = 0; i < curEntry; i++) {
Entry entry = entries[i];
int written;
if (entry.type() == INFO) {
written = fprintf(out, "I,%s\n", entry.text());
} else {
if (entry.textId() > 0) {
if (entry.text()) {
written = fprintf(out, "%llu,%s,%s,%d\n",
(unsigned long long)entry.tick(),
typeName[entry.type()],
entry.text(),
entry.lineno());
} else {
written = fprintf(out, "%llu,%s,%d,%d\n",
(unsigned long long)entry.tick(),
typeName[entry.type()],
entry.textId(),
entry.lineno());
}
} else {
written = fprintf(out, "%llu,%s\n",
(unsigned long long)entry.tick(),
typeName[entry.type()]);
}
if (threadLoggers.initialized()) {
for (ThreadLoggerHashMap::Range r = threadLoggers.all(); !r.empty(); r.popFront()) {
delete r.front().value();
}
// A logging file can only be 2GB of length (fwrite limit).
if (written < 0) {
fprintf(stderr, "Writing tracelog to disk failed,");
fprintf(stderr, "probably because the file would've exceeded the maximum size of 2GB");
fclose(out);
exit(-1);
}
if (entries[i].text() != nullptr) {
js_free(entries[i].text());
entries[i].text_ = nullptr;
}
}
curEntry = 0;
}
TraceLogging*
TraceLogging::getLogger(Logger id)
{
if (!loggers[id]) {
loggers[id] = new TraceLogging(id);
if (!atexitSet) {
startupTime = rdtsc();
atexit (releaseLoggers);
atexitSet = true;
}
threadLoggers.finish();
}
return loggers[id];
}
void
TraceLogging::releaseLoggers()
{
for (size_t i = 0; i < LAST_LOGGER; i++) {
if (!loggers[i])
continue;
delete loggers[i];
loggers[i] = nullptr;
if (lock) {
PR_DestroyLock(lock);
lock = nullptr;
}
enabled = false;
}
/* Helper functions for asm calls */
void
js::TraceLog(TraceLogging* logger, TraceLogging::Type type, JSScript* script)
bool
TraceLogging::lazyInit()
{
logger->log(type, script);
if (initialized)
return enabled;
initialized = true;
out = fopen(TRACE_LOG_DIR "tl-data.json", "w");
if (!out)
return false;
fprintf(out, "[");
if (!threadLoggers.init())
return false;
startupTime = rdtsc();
enabled = true;
return true;
}
void
js::TraceLog(TraceLogging* logger, const char* log)
TraceLogger *
js::TraceLoggerForMainThread(JSRuntime *runtime)
{
logger->log(log);
return traceLoggers.forMainThread(runtime);
}
void
js::TraceLog(TraceLogging* logger, TraceLogging::Type type)
TraceLogger *
TraceLogging::forMainThread(JSRuntime *runtime)
{
logger->log(type);
if (!runtime->mainThread.traceLogger) {
AutoTraceLoggingLock lock(this);
if (!lazyInit())
return nullptr;
runtime->mainThread.traceLogger = create();
}
return runtime->mainThread.traceLogger;
}
TraceLogger *
js::TraceLoggerForThread(PRThread *thread)
{
return traceLoggers.forThread(thread);
}
TraceLogger *
TraceLogging::forThread(PRThread *thread)
{
AutoTraceLoggingLock lock(this);
if (!lazyInit())
return nullptr;
ThreadLoggerHashMap::AddPtr p = threadLoggers.lookupForAdd(thread);
if (p)
return p->value();
TraceLogger *logger = create();
if (!logger)
return nullptr;
if (!threadLoggers.add(p, thread, logger)) {
delete logger;
return nullptr;
}
return logger;
}
TraceLogger *
TraceLogging::create()
{
if (loggerId > 999) {
fprintf(stderr, "TraceLogging: Can't create more than 999 different loggers.");
return nullptr;
}
if (loggerId > 0) {
int written = fprintf(out, ",\n");
if (written < 0)
fprintf(stderr, "TraceLogging: Error while writing.\n");
}
fprintf(out, "{\"tree\":\"tl-tree.%d.tl\", \"events\":\"tl-event.%d.tl\", \"dict\":\"tl-dict.%d.json\", \"treeFormat\":\"64,64,31,1,32\"}",
loggerId, loggerId, loggerId);
loggerId++;
TraceLogger *logger = new TraceLogger();
if (!logger)
return nullptr;
if (!logger->init(loggerId)) {
delete logger;
return nullptr;
}
return logger;
}

View File

@ -7,157 +7,503 @@
#ifndef TraceLogging_h
#define TraceLogging_h
#include <stdint.h>
#include <stdio.h>
#include "jsalloc.h"
#ifdef JS_THREADSAFE
# include "jslock.h"
#endif
#include "mozilla/GuardObjects.h"
#include "js/HashTable.h"
#include "js/TypeDecls.h"
class PRThread;
struct JSRuntime;
namespace JS {
class ReadOnlyCompileOptions;
class ReadOnlyCompileOptions;
}
namespace js {
class TraceLogging
{
/*
* Tracelogging overview.
*
* Tracelogging makes it possible to trace the timestamp of a single event and/or
* the duration of an event. This is implemented to give an as low overhead as
* possible so it doesn't interfere with running.
*
* The output of a tracelogging session is saved in /tmp/tl-data.json.
* The format of that file is a JS array per tracelogger (=thread), with a map
* containing:
* - dict: Name of the file containing a json table with the log text.
* All other files only contain a index to this table when logging.
* - events: Name of the file containing a flat list of log events saved
* in binary format.
* (64bit: Time Stamp Counter, 32bit index to dict)
* - tree: Name of the file containing the events with duration. The content
* is already in a tree data structure. This is also saved in a
* binary file.
* - treeFormat: The format used to encode the tree. By default "64,64,31,1,32".
* There are currently no other formats to save the tree.
* - 64,64,31,1,31 signifies how many bytes are used for the different
* parts of the tree.
* => 64 bits: Time Stamp Counter of start of event.
* => 64 bits: Time Stamp Counter of end of event.
* => 31 bits: Index to dict file containing the log text.
* => 1 bit: Boolean signifying if this entry has children.
* When true, the child can be found just behind this entry.
* => 32 bits: Containing the ID of the next event on the same depth
* or 0 if there isn't an event on the same depth anymore.
*
* /-> The position in the file. Id is this divided by size of entry.
* | So in this case this would be 1 (192bits per entry).
* | /-> Indicates there are children. The
* | | first child is located at current
* | | ID + 1. So 1 + 1 in this case: 2.
* | | Or 0x00180 in the tree file.
* | | /-> Next event on the same depth is
* | | | located at 4. So 0x00300 in the
* | | | tree file.
* 0x0000C0: [start, end, dictId, 1, 4]
*
*
* Example:
* 0x0: [start, end, dictId, 1, 0]
* |
* /----------------------------------\
* | |
* 0xC0: [start, end, dictId, 0, 2] 0x180 [start, end, dictId, 1, 0]
* |
* /----------------------------------\
* | |
* 0x240: [start, end, dictId, 0, 4] 0x300 [start, end, dictId, 0, 0]
*
*
* Logging something is done in 3 stages.
* 1) Get the tracelogger of the current thread.
* - TraceLoggerForMainThread(JSRuntime *)
* - TraceLoggerForThread(PR_GetCurrentThread());
* 2) Optionally create a textId for the text that needs to get logged. This
* step takes some time, so try to do this beforehand, outside the hot
* path and don't do unnecessary repetitions, since it will criple
* performance.
* - TraceLogCreateTextId(logger, ...);
*
* There are also some text IDs created beforehand. They are located in
* Tracelogger::TextId.
* 3) Log the timestamp of an event:
* - TraceLogTimestamp(logger, textId);
*
* or the duration:
* - TraceLogStartEvent(logger, textId);
* - TraceLogStopEvent(logger, textId);
*
* or the duration with a RAII class:
* - AutoTraceLog logger(logger, textId);
*/
class AutoTraceLog;
template <class T>
class ContinuousSpace {
T *data_;
uint32_t next_;
uint32_t capacity_;
public:
enum Type {
SCRIPT_START,
SCRIPT_STOP,
ION_COMPILE_START,
ION_COMPILE_STOP,
YARR_JIT_START,
YARR_JIT_STOP,
GC_START,
GC_STOP,
MINOR_GC_START,
MINOR_GC_STOP,
GC_SWEEPING_START,
GC_SWEEPING_STOP,
GC_ALLOCATING_START,
GC_ALLOCATING_STOP,
PARSER_COMPILE_SCRIPT_START,
PARSER_COMPILE_SCRIPT_STOP,
PARSER_COMPILE_LAZY_START,
PARSER_COMPILE_LAZY_STOP,
PARSER_COMPILE_FUNCTION_START,
PARSER_COMPILE_FUNCTION_STOP,
INFO_ENGINE_INTERPRETER,
INFO_ENGINE_BASELINE,
INFO_ENGINE_IONMONKEY,
INFO
};
enum Logger {
DEFAULT,
ION_BACKGROUND_COMPILER,
GC_BACKGROUND,
ContinuousSpace ()
: data_(nullptr)
{ }
LAST_LOGGER
};
bool init() {
capacity_ = 64;
next_ = 0;
data_ = (T *) js_malloc(capacity_ * sizeof(T));
if (!data_)
return false;
private:
struct Entry {
uint64_t tick_;
char* text_;
uint32_t textId_;
uint32_t lineno_;
uint8_t type_;
Entry(uint64_t tick, char* text, uint32_t textId, uint32_t lineno, Type type)
: tick_(tick),
text_(text),
textId_(textId),
lineno_(lineno),
type_((uint8_t)type) {}
uint64_t tick() const { return tick_; }
char *text() const { return text_; }
uint32_t textId() const { return textId_; }
uint32_t lineno() const { return lineno_; }
Type type() const { return (Type) type_; }
};
typedef HashMap<const char *,
uint32_t,
PointerHasher<const char *, 3>,
SystemAllocPolicy> TextHashMap;
TextHashMap textMap;
uint32_t nextTextId;
Entry *entries;
unsigned int curEntry;
unsigned int numEntries;
int fileno;
FILE *out;
Logger id;
static bool atexitSet;
static const char * const typeName[];
static TraceLogging* loggers[];
static uint64_t startupTime;
public:
TraceLogging(Logger id);
~TraceLogging();
void log(Type type, const char* text = nullptr, unsigned int number = 0);
void log(Type type, const JS::ReadOnlyCompileOptions &options);
void log(Type type, JSScript* script);
void log(const char* log);
void flush();
static TraceLogging* getLogger(Logger id);
static TraceLogging* defaultLogger() {
return getLogger(DEFAULT);
return true;
}
static void releaseLoggers();
private:
void grow();
T *data() {
return data_;
}
uint32_t capacity() {
return capacity_;
}
uint32_t size() {
return next_;
}
uint32_t nextId() {
return next_;
}
T &next() {
return data()[next_];
}
uint32_t currentId() {
JS_ASSERT(next_ > 0);
return next_ - 1;
}
T &current() {
return data()[currentId()];
}
bool ensureSpaceBeforeAdd() {
if (next_ < capacity_)
return true;
uint32_t nCapacity = capacity_ * 2;
T *entries = (T *) js_realloc(data_, nCapacity * sizeof(T));
if (!entries)
return false;
data_ = entries;
capacity_ = nCapacity;
return true;
}
T &operator[](size_t i) {
MOZ_ASSERT(i < next_);
return data()[i];
}
void push(T &data) {
MOZ_ASSERT(next_ < capacity_);
data()[next_++] = data;
}
T &pushUninitialized() {
return data()[next_++];
}
void pop() {
JS_ASSERT(next_ > 0);
next_--;
}
void clear() {
next_ = 0;
}
};
/* Helpers functions for asm calls */
void TraceLog(TraceLogging* logger, TraceLogging::Type type, JSScript* script);
void TraceLog(TraceLogging* logger, const char* log);
void TraceLog(TraceLogging* logger, TraceLogging::Type type);
class TraceLogger
{
public:
// Predefined IDs for common operations. These IDs can be used
// without using TraceLogCreateTextId, because there are already created.
// When changing the enum here, you must update the array containing the
// actual logged text in TraceLogging.cpp.
enum TextId {
TL_Error,
Bailout,
Baseline,
GC,
GCAllocating,
GCSweeping,
Interpreter,
Invalidation,
IonCompile,
IonLink,
IonMonkey,
MinorGC,
ParserCompileFunction,
ParserCompileLazy,
ParserCompileScript,
TL,
YarrCompile,
YarrInterpret,
YarrJIT,
/* Automatic logging at the start and end of function call */
class AutoTraceLog {
TraceLogging* logger;
TraceLogging::Type stop;
LAST
};
#ifdef JS_TRACE_LOGGING
private:
typedef HashMap<const void *,
uint32_t,
PointerHasher<const void *, 3>,
SystemAllocPolicy> PointerHashMap;
// The layout of the tree in memory and in the log file. Readable by JS
// using TypedArrays.
struct TreeEntry {
uint64_t start;
uint64_t stop;
union {
struct {
uint32_t textId: 31;
uint32_t hasChildren: 1;
} s;
uint32_t value;
} u;
uint32_t nextId;
TreeEntry(uint64_t start, uint64_t stop, uint32_t textId, bool hasChildren,
uint32_t nextId)
{
this->start = start;
this->stop = stop;
this->u.s.textId = textId;
this->u.s.hasChildren = hasChildren;
this->nextId = nextId;
}
};
// Helper structure for keeping track of the currently active entries in
// the tree. Pushed by `start(id)`, popped by `stop(id)`.
struct StackEntry {
uint32_t treeId;
uint32_t lastChildId;
StackEntry(uint32_t treeId, uint32_t lastChildId)
: treeId(treeId), lastChildId(lastChildId)
{ }
};
// The layout of the event log in memory and in the log file.
// Readable by JS using TypedArrays.
struct EventEntry {
uint64_t time;
uint32_t textId;
EventEntry(uint64_t time, uint32_t textId)
: time(time), textId(textId)
{ }
};
FILE *dictFile;
FILE *treeFile;
FILE *eventFile;
bool enabled;
uint32_t nextTextId;
PointerHashMap pointerMap;
ContinuousSpace<TreeEntry> tree;
ContinuousSpace<StackEntry> stack;
ContinuousSpace<EventEntry> events;
uint32_t treeOffset;
public:
AutoTraceLog(TraceLogging* logger, TraceLogging::Type start, TraceLogging::Type stop,
const JS::ReadOnlyCompileOptions &options)
: logger(logger),
stop(stop)
{
logger->log(start, options);
}
AutoTraceLog *top;
AutoTraceLog(TraceLogging* logger, TraceLogging::Type start, TraceLogging::Type stop,
JSScript* script)
: logger(logger),
stop(stop)
{
logger->log(start, script);
}
private:
void updateHasChildren(uint32_t treeId, bool hasChildren = false);
void updateNextId(uint32_t treeId, bool nextId);
void updateStop(uint32_t treeId, uint64_t timestamp);
void flush();
AutoTraceLog(TraceLogging* logger, TraceLogging::Type start, TraceLogging::Type stop)
public:
TraceLogger();
~TraceLogger();
bool init(uint32_t loggerId);
// The createTextId functions map a unique input to a logger ID.
// This ID can be used to log something. Calls to these functions should be
// limited if possible, because of the overhead.
uint32_t createTextId(const char *text);
uint32_t createTextId(JSScript *script);
uint32_t createTextId(const JS::ReadOnlyCompileOptions &script);
// Log an event (no start/stop, only the timestamp is recorded).
void logTimestamp(uint32_t id);
// Record timestamps for start and stop of an event.
// In the stop method, the ID is only used in debug builds to test
// correctness.
void startEvent(uint32_t id);
void stopEvent(uint32_t id);
void stopEvent();
private:
void assertNoQuotes(const char *text) {
#ifdef DEBUG
const char *quote = strchr(text, '"');
MOZ_ASSERT(!quote);
#endif
}
#endif
};
class TraceLogging
{
#ifdef JS_TRACE_LOGGING
typedef HashMap<PRThread *,
TraceLogger *,
PointerHasher<PRThread *, 3>,
SystemAllocPolicy> ThreadLoggerHashMap;
bool initialized;
bool enabled;
ThreadLoggerHashMap threadLoggers;
uint32_t loggerId;
FILE *out;
public:
uint64_t startupTime;
#ifdef JS_THREADSAFE
PRLock *lock;
#endif
TraceLogging();
~TraceLogging();
TraceLogger *forMainThread(JSRuntime *runtime);
TraceLogger *forThread(PRThread *thread);
private:
TraceLogger *create();
bool lazyInit();
#endif
};
#ifdef JS_TRACE_LOGGING
TraceLogger *TraceLoggerForMainThread(JSRuntime *runtime);
TraceLogger *TraceLoggerForThread(PRThread *thread);
#else
inline TraceLogger *TraceLoggerForMainThread(JSRuntime *runtime) {
return nullptr;
};
inline TraceLogger *TraceLoggerForThread(PRThread *thread) {
return nullptr;
};
#endif
inline uint32_t TraceLogCreateTextId(TraceLogger *logger, JSScript *script) {
#ifdef JS_TRACE_LOGGING
if (logger)
return logger->createTextId(script);
#endif
return TraceLogger::TL_Error;
}
inline uint32_t TraceLogCreateTextId(TraceLogger *logger,
const JS::ReadOnlyCompileOptions &compileOptions)
{
#ifdef JS_TRACE_LOGGING
if (logger)
return logger->createTextId(compileOptions);
#endif
return TraceLogger::TL_Error;
}
inline uint32_t TraceLogCreateTextId(TraceLogger *logger, const char *text) {
#ifdef JS_TRACE_LOGGING
if (logger)
return logger->createTextId(text);
#endif
return TraceLogger::TL_Error;
}
inline void TraceLogTimestamp(TraceLogger *logger, uint32_t textId) {
#ifdef JS_TRACE_LOGGING
if (logger)
logger->logTimestamp(textId);
#endif
}
inline void TraceLogStartEvent(TraceLogger *logger, uint32_t textId) {
#ifdef JS_TRACE_LOGGING
if (logger)
logger->startEvent(textId);
#endif
}
inline void TraceLogStopEvent(TraceLogger *logger, uint32_t textId) {
#ifdef JS_TRACE_LOGGING
if (logger)
logger->stopEvent(textId);
#endif
}
inline void TraceLogStopEvent(TraceLogger *logger) {
#ifdef JS_TRACE_LOGGING
if (logger)
logger->stopEvent();
#endif
}
// Automatic logging at the start and end of function call.
class AutoTraceLog {
#ifdef JS_TRACE_LOGGING
TraceLogger *logger;
uint32_t textId;
bool executed;
AutoTraceLog *prev;
public:
AutoTraceLog(TraceLogger *logger, uint32_t textId MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
: logger(logger),
stop(stop)
textId(textId),
executed(false)
{
logger->log(start);
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
if (logger) {
TraceLogStartEvent(logger, textId);
prev = logger->top;
logger->top = this;
}
}
~AutoTraceLog()
{
logger->log(stop);
if (logger) {
while (this != logger->top)
logger->top->stop();
stop();
}
}
private:
void stop() {
if (!executed) {
executed = true;
TraceLogStopEvent(logger, textId);
}
if (logger->top == this)
logger->top = prev;
}
#else
public:
AutoTraceLog(TraceLogger *logger, uint32_t textId MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
{
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
}
#endif
private:
MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
};
} /* namespace js */
#ifdef JS_TRACE_LOGGING
class AutoTraceLoggingLock
{
TraceLogging *logging;
public:
AutoTraceLoggingLock(TraceLogging *logging MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
: logging(logging)
{
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
#ifdef JS_THREADSAFE
PR_Lock(logging->lock);
#endif
}
~AutoTraceLoggingLock() {
#ifdef JS_THREADSAFE
PR_Unlock(logging->lock);
#endif
}
private:
MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
};
#endif
} /* namedata js */
#endif /* TraceLogging_h */

View File

@ -8,6 +8,7 @@
#include "jscntxt.h"
#include "jsscript.h"
#include "TraceLogging.h"
#include "frontend/BytecodeEmitter.h"
#include "frontend/FoldConstants.h"
@ -189,12 +190,14 @@ frontend::CompileScript(ExclusiveContext *cx, LifoAlloc *alloc, HandleObject sco
{
RootedString source(cx, source_);
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::PARSER_COMPILE_SCRIPT_START,
js::TraceLogging::PARSER_COMPILE_SCRIPT_STOP,
options);
#endif
js::TraceLogger *logger = nullptr;
if (cx->isJSContext())
logger = TraceLoggerForMainThread(cx->asJSContext()->runtime());
else
logger = TraceLoggerForThread(PR_GetCurrentThread());
uint32_t logId = js::TraceLogCreateTextId(logger, options);
js::AutoTraceLog scriptLogger(logger, logId);
js::AutoTraceLog typeLogger(logger, TraceLogger::ParserCompileScript);
if (cx->isJSContext())
MaybeCallSourceHandler(cx->asJSContext(), options, chars, length);
@ -437,12 +440,10 @@ frontend::CompileLazyFunction(JSContext *cx, Handle<LazyScript*> lazy, const jsc
.setNoScriptRval(false)
.setSelfHostingMode(false);
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::PARSER_COMPILE_LAZY_START,
js::TraceLogging::PARSER_COMPILE_LAZY_STOP,
options);
#endif
js::TraceLogger *logger = js::TraceLoggerForMainThread(cx->runtime());
uint32_t logId = js::TraceLogCreateTextId(logger, options);
js::AutoTraceLog scriptLogger(logger, logId);
js::AutoTraceLog typeLogger(logger, TraceLogger::ParserCompileLazy);
Parser<FullParseHandler> parser(cx, &cx->tempLifoAlloc(), options, chars, length,
/* foldConstants = */ true, nullptr, lazy);
@ -497,12 +498,10 @@ CompileFunctionBody(JSContext *cx, MutableHandleFunction fun, const ReadOnlyComp
const AutoNameVector &formals, const jschar *chars, size_t length,
GeneratorKind generatorKind)
{
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::PARSER_COMPILE_FUNCTION_START,
js::TraceLogging::PARSER_COMPILE_FUNCTION_STOP,
options);
#endif
js::TraceLogger *logger = js::TraceLoggerForMainThread(cx->runtime());
uint32_t logId = js::TraceLogCreateTextId(logger, options);
js::AutoTraceLog scriptLogger(logger, logId);
js::AutoTraceLog typeLogger(logger, TraceLogger::ParserCompileFunction);
// FIXME: make Function pass in two strings and parse them as arguments and
// ProgramElements respectively.

View File

@ -7,6 +7,7 @@
#include "jit/Bailouts.h"
#include "jscntxt.h"
#include "TraceLogging.h"
#include "jit/BaselineJIT.h"
#include "jit/Ion.h"
@ -78,6 +79,9 @@ jit::Bailout(BailoutStack *sp, BaselineBailoutInfo **bailoutInfo)
IonBailoutIterator iter(jitActivations, sp);
JitActivation *activation = jitActivations.activation()->asJit();
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
TraceLogTimestamp(logger, TraceLogger::Bailout);
IonSpew(IonSpew_Bailouts, "Took bailout! Snapshot offset: %d", iter.snapshotOffset());
JS_ASSERT(IsBaselineEnabled(cx));
@ -109,6 +113,9 @@ jit::InvalidationBailout(InvalidationBailoutStack *sp, size_t *frameSizeOut,
IonBailoutIterator iter(jitActivations, sp);
JitActivation *activation = jitActivations.activation()->asJit();
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
TraceLogTimestamp(logger, TraceLogger::Invalidation);
IonSpew(IonSpew_Bailouts, "Took invalidation bailout! Snapshot offset: %d", iter.snapshotOffset());
// Note: the frame size must be computed before we return from this function.

View File

@ -1261,9 +1261,9 @@ jit::BailoutIonToBaseline(JSContext *cx, JitActivation *activation, IonBailoutIt
JS_ASSERT(bailoutInfo != nullptr);
JS_ASSERT(*bailoutInfo == nullptr);
#if JS_TRACE_LOGGING
TraceLogging::defaultLogger()->log(TraceLogging::INFO_ENGINE_BASELINE);
#endif
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
TraceLogStopEvent(logger, TraceLogger::IonMonkey);
TraceLogStartEvent(logger, TraceLogger::Baseline);
// The caller of the top frame must be one of the following:
// IonJS - Ion calling into Ion.
@ -1351,12 +1351,11 @@ jit::BailoutIonToBaseline(JSContext *cx, JitActivation *activation, IonBailoutIt
while (true) {
MOZ_ASSERT(snapIter.instruction()->isResumePoint());
#if JS_TRACE_LOGGING
if (frameNo > 0) {
TraceLogging::defaultLogger()->log(TraceLogging::SCRIPT_START, scr);
TraceLogging::defaultLogger()->log(TraceLogging::INFO_ENGINE_BASELINE);
TraceLogStartEvent(logger, TraceLogCreateTextId(logger, scr));
TraceLogStartEvent(logger, TraceLogger::Baseline);
}
#endif
IonSpew(IonSpew_BaselineBailouts, " FrameNo %d", frameNo);
// If we are bailing out to a catch or finally block in this frame,

View File

@ -345,8 +345,13 @@ BaselineCompiler::emitPrologue()
masm.bind(&earlyStackCheckFailed);
#if JS_TRACE_LOGGING
masm.tracelogStart(script.get());
masm.tracelogLog(TraceLogging::INFO_ENGINE_BASELINE);
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
Register loggerReg = RegisterSet::Volatile().takeGeneral();
masm.Push(loggerReg);
masm.movePtr(ImmPtr(logger), loggerReg);
masm.tracelogStart(loggerReg, TraceLogCreateTextId(logger, script.get()));
masm.tracelogStart(loggerReg, TraceLogger::Baseline);
masm.Pop(loggerReg);
#endif
// Record the offset of the prologue, because Ion can bailout before
@ -382,7 +387,15 @@ BaselineCompiler::emitEpilogue()
masm.bind(&return_);
#if JS_TRACE_LOGGING
masm.tracelogStop();
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
Register loggerReg = RegisterSet::Volatile().takeGeneral();
masm.Push(loggerReg);
masm.movePtr(ImmPtr(logger), loggerReg);
masm.tracelogStop(loggerReg, TraceLogger::Baseline);
// Stop the script. Using a stop without checking the textId, since we
// we didn't save the textId for the script.
masm.tracelogStop(loggerReg);
masm.Pop(loggerReg);
#endif
// Pop SPS frame if necessary

View File

@ -200,9 +200,9 @@ jit::EnterBaselineAtBranch(JSContext *cx, InterpreterFrame *fp, jsbytecode *pc)
data.calleeToken = CalleeToToken(fp->script());
}
#if JS_TRACE_LOGGING
TraceLogging::defaultLogger()->log(TraceLogging::INFO_ENGINE_BASELINE);
#endif
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
TraceLogStopEvent(logger, TraceLogger::Interpreter);
TraceLogStartEvent(logger, TraceLogger::Baseline);
IonExecStatus status = EnterBaseline(cx, data);
if (status != IonExec_Ok)

View File

@ -1288,7 +1288,12 @@ CodeGenerator::visitOsrEntry(LOsrEntry *lir)
setOsrEntryOffset(masm.size());
#if JS_TRACE_LOGGING
masm.tracelogLog(TraceLogging::INFO_ENGINE_IONMONKEY);
if (gen->info().executionMode() == SequentialExecution) {
if (!emitTracelogStopEvent(TraceLogger::Baseline))
return false;
if (!emitTracelogStartEvent(TraceLogger::IonMonkey))
return false;
}
#endif
// Allocate the full frame for this function.
@ -6249,8 +6254,12 @@ CodeGenerator::generate()
return false;
#if JS_TRACE_LOGGING
masm.tracelogStart(gen->info().script());
masm.tracelogLog(TraceLogging::INFO_ENGINE_IONMONKEY);
if (!gen->compilingAsmJS() && gen->info().executionMode() == SequentialExecution) {
if (!emitTracelogScriptStart())
return false;
if (!emitTracelogStartEvent(TraceLogger::IonMonkey))
return false;
}
#endif
// Before generating any code, we generate type checks for all parameters.
@ -6275,8 +6284,12 @@ CodeGenerator::generate()
setSkipArgCheckEntryOffset(masm.size());
#if JS_TRACE_LOGGING
masm.tracelogStart(gen->info().script());
masm.tracelogLog(TraceLogging::INFO_ENGINE_IONMONKEY);
if (!gen->compilingAsmJS() && gen->info().executionMode() == SequentialExecution) {
if (!emitTracelogScriptStart())
return false;
if (!emitTracelogStartEvent(TraceLogger::IonMonkey))
return false;
}
masm.bind(&skip);
#endif
@ -6469,6 +6482,23 @@ CodeGenerator::link(JSContext *cx, types::CompilerConstraintList *constraints)
if (patchableBackedges_.length() > 0)
ionScript->copyPatchableBackedges(cx, code, patchableBackedges_.begin());
#if JS_TRACE_LOGGING
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
for (uint32_t i = 0; i < patchableTraceLoggers_.length(); i++) {
patchableTraceLoggers_[i].fixup(&masm);
Assembler::patchDataWithValueCheck(CodeLocationLabel(code, patchableTraceLoggers_[i]),
ImmPtr(logger),
ImmPtr(nullptr));
}
uint32_t scriptId = TraceLogCreateTextId(logger, script);
for (uint32_t i = 0; i < patchableTLScripts_.length(); i++) {
patchableTLScripts_[i].fixup(&masm);
Assembler::patchDataWithValueCheck(CodeLocationLabel(code, patchableTLScripts_[i]),
ImmPtr((void *)scriptId),
ImmPtr((void *)0));
}
#endif
switch (executionMode) {
case SequentialExecution:
// The correct state for prebarriers is unknown until the end of compilation,

View File

@ -11,9 +11,7 @@
#include "jscompartment.h"
#include "jsworkers.h"
#if JS_TRACE_LOGGING
#include "TraceLogging.h"
#endif
#include "jsprf.h"
#include "gc/Marking.h"
@ -1635,6 +1633,8 @@ AttachFinishedCompilations(JSContext *cx)
GlobalWorkerThreadState::IonBuilderVector &finished = WorkerThreadState().ionFinishedList();
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
// Incorporate any off thread compilations for the compartment which have
// finished, failed or have been cancelled.
while (true) {
@ -1655,6 +1655,8 @@ AttachFinishedCompilations(JSContext *cx)
if (CodeGenerator *codegen = builder->backgroundCodegen()) {
RootedScript script(cx, builder->script());
IonContext ictx(cx, &builder->alloc());
AutoTraceLog logScript(logger, TraceLogCreateTextId(logger, script));
AutoTraceLog logLink(logger, TraceLogger::IonLink);
// Root the assembler until the builder is finished below. As it
// was constructed off thread, the assembler has not been rooted
@ -1748,12 +1750,10 @@ IonCompile(JSContext *cx, JSScript *script,
ExecutionMode executionMode, bool recompile,
OptimizationLevel optimizationLevel)
{
#if JS_TRACE_LOGGING
AutoTraceLog logger(TraceLogging::defaultLogger(),
TraceLogging::ION_COMPILE_START,
TraceLogging::ION_COMPILE_STOP,
script);
#endif
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
AutoTraceLog logScript(logger, TraceLogCreateTextId(logger, script));
AutoTraceLog logCompile(logger, TraceLogger::IonCompile);
JS_ASSERT(optimizationLevel > Optimization_DontCompile);
// Make sure the script's canonical function isn't lazy. We can't de-lazify

View File

@ -1138,66 +1138,116 @@ MacroAssembler::printf(const char *output, Register value)
#if JS_TRACE_LOGGING
void
MacroAssembler::tracelogStart(JSScript *script)
MacroAssembler::tracelogStart(Register logger, uint32_t textId)
{
void (&TraceLogStart)(TraceLogging*, TraceLogging::Type, JSScript*) = TraceLog;
void (&TraceLogFunc)(TraceLogger*, uint32_t) = TraceLogStartEvent;
PushRegsInMask(RegisterSet::Volatile());
RegisterSet regs = RegisterSet::Volatile();
PushRegsInMask(regs);
regs.takeUnchecked(logger);
Register temp = regs.takeGeneral();
Register type = regs.takeGeneral();
Register rscript = regs.takeGeneral();
setupUnalignedABICall(3, temp);
movePtr(ImmPtr(TraceLogging::defaultLogger()), temp);
setupUnalignedABICall(2, temp);
passABIArg(logger);
move32(Imm32(textId), temp);
passABIArg(temp);
move32(Imm32(TraceLogging::SCRIPT_START), type);
passABIArg(type);
movePtr(ImmGCPtr(script), rscript);
passABIArg(rscript);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogStart));
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogFunc));
PopRegsInMask(RegisterSet::Volatile());
}
void
MacroAssembler::tracelogStop()
MacroAssembler::tracelogStart(Register logger, Register textId)
{
void (&TraceLogStop)(TraceLogging*, TraceLogging::Type) = TraceLog;
void (&TraceLogFunc)(TraceLogger*, uint32_t) = TraceLogStartEvent;
PushRegsInMask(RegisterSet::Volatile());
RegisterSet regs = RegisterSet::Volatile();
PushRegsInMask(regs);
regs.takeUnchecked(logger);
regs.takeUnchecked(textId);
Register temp = regs.takeGeneral();
Register logger = regs.takeGeneral();
Register type = regs.takeGeneral();
setupUnalignedABICall(2, temp);
movePtr(ImmPtr(TraceLogging::defaultLogger()), logger);
passABIArg(logger);
move32(Imm32(TraceLogging::SCRIPT_STOP), type);
passABIArg(type);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogStop));
passABIArg(textId);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogFunc));
regs.add(temp);
PopRegsInMask(RegisterSet::Volatile());
}
void
MacroAssembler::tracelogLog(TraceLogging::Type type)
MacroAssembler::tracelogStop(Register logger, uint32_t textId)
{
void (&TraceLogStop)(TraceLogging*, TraceLogging::Type) = TraceLog;
void (&TraceLogFunc)(TraceLogger*, uint32_t) = TraceLogStopEvent;
PushRegsInMask(RegisterSet::Volatile());
RegisterSet regs = RegisterSet::Volatile();
PushRegsInMask(regs);
regs.takeUnchecked(logger);
Register temp = regs.takeGeneral();
Register logger = regs.takeGeneral();
Register rtype = regs.takeGeneral();
setupUnalignedABICall(2, temp);
movePtr(ImmPtr(TraceLogging::defaultLogger()), logger);
passABIArg(logger);
move32(Imm32(type), rtype);
passABIArg(rtype);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogStop));
move32(Imm32(textId), temp);
passABIArg(temp);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogFunc));
regs.add(temp);
PopRegsInMask(RegisterSet::Volatile());
}
void
MacroAssembler::tracelogStop(Register logger, Register textId)
{
#ifdef DEBUG
void (&TraceLogFunc)(TraceLogger*, uint32_t) = TraceLogStopEvent;
PushRegsInMask(RegisterSet::Volatile());
RegisterSet regs = RegisterSet::Volatile();
regs.takeUnchecked(logger);
regs.takeUnchecked(textId);
Register temp = regs.takeGeneral();
setupUnalignedABICall(2, temp);
passABIArg(logger);
passABIArg(textId);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogFunc));
regs.add(temp);
PopRegsInMask(RegisterSet::Volatile());
#else
tracelogStop(logger);
#endif
}
void
MacroAssembler::tracelogStop(Register logger)
{
void (&TraceLogFunc)(TraceLogger*) = TraceLogStopEvent;
PushRegsInMask(RegisterSet::Volatile());
RegisterSet regs = RegisterSet::Volatile();
regs.takeUnchecked(logger);
Register temp = regs.takeGeneral();
setupUnalignedABICall(1, temp);
passABIArg(logger);
callWithABINoProfiling(JS_FUNC_TO_DATA_PTR(void *, TraceLogFunc));
regs.add(temp);
PopRegsInMask(RegisterSet::Volatile());
}

View File

@ -10,6 +10,7 @@
#ifdef JS_ION
#include "jscompartment.h"
#include "TraceLogging.h"
#if defined(JS_CODEGEN_X86)
# include "jit/x86/MacroAssembler-x86.h"
@ -1123,9 +1124,11 @@ class MacroAssembler : public MacroAssemblerSpecific
void printf(const char *output, Register value);
#if JS_TRACE_LOGGING
void tracelogStart(JSScript *script);
void tracelogStop();
void tracelogLog(TraceLogging::Type type);
void tracelogStart(Register logger, uint32_t textId);
void tracelogStart(Register logger, Register textId);
void tracelogStop(Register logger, uint32_t textId);
void tracelogStop(Register logger, Register textId);
void tracelogStop(Register logger);
#endif
#define DISPATCH_FLOATING_POINT_OP(method, type, arg1d, arg1f, arg2) \

View File

@ -56,9 +56,16 @@ bool
CodeGeneratorARM::generateEpilogue()
{
masm.bind(&returnLabel_);
#if JS_TRACE_LOGGING
masm.tracelogStop();
if (!gen->compilingAsmJS() && gen->info().executionMode() == SequentialExecution) {
if (!emitTracelogStopEvent(TraceLogger::IonMonkey))
return false;
if (!emitTracelogScriptStop())
return false;
}
#endif
if (gen->compilingAsmJS()) {
// Pop the stack we allocated at the start of the function.
masm.freeStack(frameDepth_);

View File

@ -995,5 +995,75 @@ CodeGeneratorShared::addCacheLocations(const CacheLocationList &locs, size_t *nu
return firstIndex;
}
#if JS_TRACE_LOGGING
bool
CodeGeneratorShared::emitTracelogScript(bool isStart)
{
RegisterSet regs = RegisterSet::Volatile();
Register logger = regs.takeGeneral();
Register script = regs.takeGeneral();
masm.Push(logger);
masm.Push(script);
CodeOffsetLabel patchLogger = masm.movWithPatch(ImmPtr(nullptr), logger);
if (!patchableTraceLoggers_.append(patchLogger))
return false;
CodeOffsetLabel patchScript = masm.movWithPatch(ImmWord(0), script);
if (!patchableTLScripts_.append(patchScript))
return false;
if (isStart)
masm.tracelogStart(logger, script);
else
masm.tracelogStop(logger, script);
masm.Pop(script);
masm.Pop(logger);
return true;
}
bool
CodeGeneratorShared::emitTracelogTree(bool isStart, uint32_t textId)
{
RegisterSet regs = RegisterSet::Volatile();
Register logger = regs.takeGeneral();
masm.Push(logger);
CodeOffsetLabel patchLocation = masm.movWithPatch(ImmPtr(nullptr), logger);
if (!patchableTraceLoggers_.append(patchLocation))
return false;
if (isStart)
masm.tracelogStart(logger, textId);
else
masm.tracelogStop(logger, textId);
masm.Pop(logger);
return true;
}
bool
CodeGeneratorShared::emitTracelogStopEvent()
{
RegisterSet regs = RegisterSet::Volatile();
Register logger = regs.takeGeneral();
masm.Push(logger);
CodeOffsetLabel patchLocation = masm.movWithPatch(ImmPtr(nullptr), logger);
if (!patchableTraceLoggers_.append(patchLocation))
return false;
masm.tracelogStop(logger);
masm.Pop(logger);
return true;
}
#endif
} // namespace jit
} // namespace js

View File

@ -89,6 +89,11 @@ class CodeGeneratorShared : public LInstructionVisitor
// Patchable backedges generated for loops.
Vector<PatchableBackedgeInfo, 0, SystemAllocPolicy> patchableBackedges_;
#if JS_TRACE_LOGGING
js::Vector<CodeOffsetLabel, 0, SystemAllocPolicy> patchableTraceLoggers_;
js::Vector<CodeOffsetLabel, 0, SystemAllocPolicy> patchableTLScripts_;
#endif
// When profiling is enabled, this is the instrumentation manager which
// maintains state of what script is currently being generated (for inline
// scripts) and when instrumentation needs to be emitted or skipped.
@ -443,6 +448,31 @@ class CodeGeneratorShared : public LInstructionVisitor
OutOfLinePropagateAbortPar *oolPropagateAbortPar(LInstruction *lir);
virtual bool visitOutOfLineAbortPar(OutOfLineAbortPar *ool) = 0;
virtual bool visitOutOfLinePropagateAbortPar(OutOfLinePropagateAbortPar *ool) = 0;
#if JS_TRACE_LOGGING
protected:
bool emitTracelogScript(bool isStart);
bool emitTracelogTree(bool isStart, uint32_t textId);
public:
bool emitTracelogScriptStart() {
return emitTracelogScript(/* isStart =*/ true);
}
bool emitTracelogScriptStop() {
return emitTracelogScript(/* isStart =*/ false);
}
bool emitTracelogStartEvent(uint32_t textId) {
return emitTracelogTree(/* isStart =*/ true, textId);
}
bool emitTracelogStopEvent(uint32_t textId) {
#ifdef DEBUG
return emitTracelogTree(/* isStart =*/ false, textId);
#else
return emitTracelogScript(/* isStart =*/ false);
#endif
}
bool emitTracelogStopEvent();
#endif
};
// An out-of-line path is generated at the end of the function.

View File

@ -49,7 +49,12 @@ CodeGeneratorX86Shared::generateEpilogue()
masm.bind(&returnLabel_);
#if JS_TRACE_LOGGING
masm.tracelogStop();
if (!gen->compilingAsmJS() && gen->info().executionMode() == SequentialExecution) {
if (!emitTracelogStopEvent(TraceLogger::IonMonkey))
return false;
if (!emitTracelogScriptStop())
return false;
}
#endif
// Pop the stack we allocated at the start of the function.

View File

@ -197,9 +197,7 @@
# include "jswin.h"
#endif
#include "prmjtime.h"
#if JS_TRACE_LOGGING
#include "TraceLogging.h"
#endif
#include "gc/FindSCCs.h"
#include "gc/GCInternals.h"
@ -2558,9 +2556,7 @@ GCHelperThread::threadLoop()
{
AutoLockGC lock(rt);
#if JS_TRACE_LOGGING
TraceLogging *logger = TraceLogging::getLogger(TraceLogging::GC_BACKGROUND);
#endif
TraceLogger *logger = TraceLoggerForThread(PR_GetCurrentThread());
/*
* Even on the first iteration the state can be SHUTDOWN or SWEEPING if
@ -2574,22 +2570,16 @@ GCHelperThread::threadLoop()
case IDLE:
wait(wakeup);
break;
case SWEEPING:
#if JS_TRACE_LOGGING
logger->log(TraceLogging::GC_SWEEPING_START);
#endif
case SWEEPING: {
AutoTraceLog logSweeping(logger, TraceLogger::GCSweeping);
doSweep();
if (state == SWEEPING)
state = IDLE;
PR_NotifyAllCondVar(done);
#if JS_TRACE_LOGGING
logger->log(TraceLogging::GC_SWEEPING_STOP);
#endif
break;
case ALLOCATING:
#if JS_TRACE_LOGGING
logger->log(TraceLogging::GC_ALLOCATING_START);
#endif
}
case ALLOCATING: {
AutoTraceLog logAllocating(logger, TraceLogger::GCAllocating);
do {
Chunk *chunk;
{
@ -2598,21 +2588,15 @@ GCHelperThread::threadLoop()
}
/* OOM stops the background allocation. */
if (!chunk) {
#if JS_TRACE_LOGGING
logger->log(TraceLogging::GC_ALLOCATING_STOP);
#endif
if (!chunk)
break;
}
JS_ASSERT(chunk->info.numArenasFreeCommitted == 0);
rt->gcChunkPool.put(chunk);
} while (state == ALLOCATING && rt->gcChunkPool.wantBackgroundAllocation(rt));
if (state == ALLOCATING)
state = IDLE;
#if JS_TRACE_LOGGING
logger->log(TraceLogging::GC_ALLOCATING_STOP);
#endif
break;
}
case CANCEL_ALLOCATION:
state = IDLE;
PR_NotifyAllCondVar(done);
@ -4908,11 +4892,8 @@ Collect(JSRuntime *rt, bool incremental, int64_t budget,
if (rt->mainThread.suppressGC)
return;
#if JS_TRACE_LOGGING
AutoTraceLog logger(TraceLogging::defaultLogger(),
TraceLogging::GC_START,
TraceLogging::GC_STOP);
#endif
TraceLogger *logger = TraceLoggerForMainThread(rt);
AutoTraceLog logGC(logger, TraceLogger::GC);
#ifdef JS_GC_ZEAL
if (rt->gcDeterministicOnly && !IsDeterministicGCReason(reason))
@ -5071,11 +5052,8 @@ void
js::MinorGC(JSRuntime *rt, JS::gcreason::Reason reason)
{
#ifdef JSGC_GENERATIONAL
#if JS_TRACE_LOGGING
AutoTraceLog logger(TraceLogging::defaultLogger(),
TraceLogging::MINOR_GC_START,
TraceLogging::MINOR_GC_STOP);
#endif
TraceLogger *logger = TraceLoggerForMainThread(rt);
AutoTraceLog logMinorGC(logger, TraceLogger::MinorGC);
rt->gcNursery.collect(rt, reason, nullptr);
JS_ASSERT_IF(!rt->mainThread.suppressGC, rt->gcNursery.isEmpty());
#endif
@ -5087,11 +5065,9 @@ js::MinorGC(JSContext *cx, JS::gcreason::Reason reason)
// Alternate to the runtime-taking form above which allows marking type
// objects as needing pretenuring.
#ifdef JSGC_GENERATIONAL
#if JS_TRACE_LOGGING
AutoTraceLog logger(TraceLogging::defaultLogger(),
TraceLogging::MINOR_GC_START,
TraceLogging::MINOR_GC_STOP);
#endif
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
AutoTraceLog logMinorGC(logger, TraceLogger::MinorGC);
Nursery::TypeObjectList pretenureTypes;
JSRuntime *rt = cx->runtime();
rt->gcNursery.collect(cx->runtime(), reason, &pretenureTypes);

View File

@ -12,6 +12,7 @@
#include "jsnativestack.h"
#include "prmjtime.h"
#include "TraceLogging.h"
#include "frontend/BytecodeCompiler.h"
#include "jit/IonBuilder.h"
@ -779,12 +780,9 @@ WorkerThread::handleIonWorkload()
ionBuilder = WorkerThreadState().ionWorklist().popCopy();
#if JS_TRACE_LOGGING
AutoTraceLog logger(TraceLogging::getLogger(TraceLogging::ION_BACKGROUND_COMPILER),
TraceLogging::ION_COMPILE_START,
TraceLogging::ION_COMPILE_STOP,
ionBuilder->script());
#endif
TraceLogger *logger = TraceLoggerForThread(thread);
AutoTraceLog logScript(logger, TraceLogCreateTextId(logger, ionBuilder->script()));
AutoTraceLog logCompile(logger, TraceLogger::IonCompile);
JSRuntime *rt = ionBuilder->script()->compartment()->runtimeFromAnyThread();

View File

@ -54,9 +54,6 @@
#include "jsworkers.h"
#include "jswrapper.h"
#include "prmjtime.h"
#if JS_TRACE_LOGGING
#include "TraceLogging.h"
#endif
#include "builtin/TestingFunctions.h"
#include "frontend/Parser.h"
@ -1542,9 +1539,6 @@ PrintInternal(JSContext *cx, const CallArgs &args, FILE *file)
if (!bytes)
return false;
fprintf(file, "%s%s", i ? " " : "", bytes);
#if JS_TRACE_LOGGING
TraceLog(TraceLogging::defaultLogger(), bytes);
#endif
JS_free(cx, bytes);
}

View File

@ -29,9 +29,7 @@
#include "jsprf.h"
#include "jsscript.h"
#include "jsstr.h"
#if JS_TRACE_LOGGING
#include "TraceLogging.h"
#endif
#include "builtin/Eval.h"
#include "jit/BaselineJIT.h"
@ -1466,10 +1464,10 @@ Interpret(JSContext *cx, RunState &state)
RootedScript script(cx);
SET_SCRIPT(REGS.fp()->script());
#if JS_TRACE_LOGGING
TraceLogging::defaultLogger()->log(TraceLogging::SCRIPT_START, script);
TraceLogging::defaultLogger()->log(TraceLogging::INFO_ENGINE_INTERPRETER);
#endif
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
uint32_t scriptLogId = TraceLogCreateTextId(logger, script);
TraceLogStartEvent(logger, scriptLogId);
TraceLogStartEvent(logger, TraceLogger::Interpreter);
/*
* Pool of rooters for use in this interpreter frame. References to these
@ -1801,9 +1799,11 @@ CASE(JSOP_RETRVAL)
if (activation.entryFrame() != REGS.fp())
inline_return:
{
#if JS_TRACE_LOGGING
TraceLogging::defaultLogger()->log(TraceLogging::SCRIPT_STOP);
#endif
// Stop the engine. (No details about which engine exactly, could be
// interpreter, Baseline or IonMonkey.)
TraceLogStopEvent(logger);
// Stop the script. (Again no details about which script exactly.)
TraceLogStopEvent(logger);
if (MOZ_UNLIKELY(cx->compartment()->debugMode()))
interpReturnOK = ScriptDebugEpilogue(cx, REGS.fp(), REGS.pc, interpReturnOK);
@ -2677,10 +2677,9 @@ CASE(JSOP_FUNCALL)
SET_SCRIPT(REGS.fp()->script());
#if JS_TRACE_LOGGING
TraceLogging::defaultLogger()->log(TraceLogging::SCRIPT_START, script);
TraceLogging::defaultLogger()->log(TraceLogging::INFO_ENGINE_INTERPRETER);
#endif
uint32_t scriptLogId = TraceLogCreateTextId(logger, script);
TraceLogStartEvent(logger, scriptLogId);
TraceLogStartEvent(logger, TraceLogger::Interpreter);
if (!REGS.fp()->prologue(cx))
goto error;
@ -3511,9 +3510,8 @@ DEFAULT()
gc::MaybeVerifyBarriers(cx, true);
#if JS_TRACE_LOGGING
TraceLogging::defaultLogger()->log(TraceLogging::SCRIPT_STOP);
#endif
TraceLogStopEvent(logger);
TraceLogStopEvent(logger, scriptLogId);
#ifdef JS_ION
/*

View File

@ -8,6 +8,8 @@
#include "mozilla/MemoryReporting.h"
#include "TraceLogging.h"
#include "frontend/TokenStream.h"
#include "vm/MatchPairs.h"
#include "vm/RegExpStatics.h"
@ -520,9 +522,14 @@ RegExpRunStatus
RegExpShared::execute(JSContext *cx, const jschar *chars, size_t length,
size_t *lastIndex, MatchPairs &matches)
{
/* Compile the code at point-of-use. */
if (!compileIfNecessary(cx))
return RegExpRunStatus_Error;
TraceLogger *logger = TraceLoggerForMainThread(cx->runtime());
{
/* Compile the code at point-of-use. */
AutoTraceLog logCompile(logger, TraceLogger::YarrCompile);
if (!compileIfNecessary(cx))
return RegExpRunStatus_Error;
}
/* Ensure sufficient memory for output vector. */
if (!matches.initArray(pairCount()))
@ -547,12 +554,18 @@ RegExpShared::execute(JSContext *cx, const jschar *chars, size_t length,
unsigned result;
#if ENABLE_YARR_JIT
if (codeBlock.isFallBack())
if (codeBlock.isFallBack()) {
AutoTraceLog logInterpret(logger, TraceLogger::YarrInterpret);
result = JSC::Yarr::interpret(cx, bytecode, chars, length, start, outputBuf);
else
} else {
AutoTraceLog logJIT(logger, TraceLogger::YarrJIT);
result = codeBlock.execute(chars, start, length, (int *)outputBuf).start;
}
#else
result = JSC::Yarr::interpret(cx, bytecode, chars, length, start, outputBuf);
{
AutoTraceLog logInterpret(logger, TraceLogger::YarrInterpret);
result = JSC::Yarr::interpret(cx, bytecode, chars, length, start, outputBuf);
}
#endif
if (result == JSC::Yarr::offsetError) {
@ -573,9 +586,14 @@ RegExpRunStatus
RegExpShared::executeMatchOnly(JSContext *cx, const jschar *chars, size_t length,
size_t *lastIndex, MatchPair &match)
{
/* Compile the code at point-of-use. */
if (!compileMatchOnlyIfNecessary(cx))
return RegExpRunStatus_Error;
TraceLogger *logger = js::TraceLoggerForMainThread(cx->runtime());
{
/* Compile the code at point-of-use. */
AutoTraceLog logCompile(logger, TraceLogger::YarrCompile);
if (!compileMatchOnlyIfNecessary(cx))
return RegExpRunStatus_Error;
}
#ifdef DEBUG
const size_t origLength = length;
@ -592,6 +610,7 @@ RegExpShared::executeMatchOnly(JSContext *cx, const jschar *chars, size_t length
#if ENABLE_YARR_JIT
if (!codeBlock.isFallBack()) {
AutoTraceLog logJIT(logger, TraceLogger::YarrJIT);
MatchResult result = codeBlock.execute(chars, start, length);
if (!result)
return RegExpRunStatus_Success_NotFound;
@ -613,8 +632,11 @@ RegExpShared::executeMatchOnly(JSContext *cx, const jschar *chars, size_t length
if (!matches.initArray(pairCount()))
return RegExpRunStatus_Error;
unsigned result =
JSC::Yarr::interpret(cx, bytecode, chars, length, start, matches.rawBuf());
unsigned result;
{
AutoTraceLog logInterpret(logger, TraceLogger::YarrInterpret);
result = JSC::Yarr::interpret(cx, bytecode, chars, length, start, matches.rawBuf());
}
if (result == JSC::Yarr::offsetError) {
reportYarrError(cx, nullptr, JSC::Yarr::RuntimeError);

View File

@ -72,6 +72,9 @@ PerThreadData::PerThreadData(JSRuntime *runtime)
ionTop(nullptr),
jitJSContext(nullptr),
jitStackLimit(0),
#if JS_TRACE_LOGGING
traceLogger(nullptr),
#endif
activation_(nullptr),
asmJSActivationStack_(nullptr),
#ifdef JS_ARM_SIMULATOR

View File

@ -56,6 +56,9 @@ namespace js {
class PerThreadData;
class ThreadSafeContext;
class AutoKeepAtoms;
#if JS_TRACE_LOGGING
class TraceLogger;
#endif
/* Thread Local Storage slot for storing the runtime for a thread. */
extern mozilla::ThreadLocal<PerThreadData*> TlsPerThreadData;
@ -538,6 +541,10 @@ class PerThreadData : public PerThreadDataFriendFields
inline void setJitStackLimit(uintptr_t limit);
#if JS_TRACE_LOGGING
TraceLogger *traceLogger;
#endif
/*
* asm.js maintains a stack of AsmJSModule activations (see AsmJS.h). This
* stack is used by JSRuntime::requestInterrupt to stop long-running asm.js

View File

@ -43,10 +43,6 @@
#define YARR_CALL
#endif
#if JS_TRACE_LOGGING
#include "TraceLogging.h"
#endif
#include "jit/JitCommon.h"
namespace JSC {
@ -99,12 +95,6 @@ public:
{
ASSERT(has8BitCode());
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::YARR_JIT_START,
js::TraceLogging::YARR_JIT_STOP);
#endif
return MatchResult(reinterpret_cast<YarrJITCode8>(m_ref8.code().executableAddress())(input, start, length, output));
}
@ -112,12 +102,6 @@ public:
{
ASSERT(has8BitCodeMatchOnly());
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::YARR_JIT_START,
js::TraceLogging::YARR_JIT_STOP);
#endif
return MatchResult(reinterpret_cast<YarrJITCodeMatchOnly8>(m_matchOnly8.code().executableAddress())(input, start, length));
}
#endif
@ -126,12 +110,6 @@ public:
{
ASSERT(has16BitCode());
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::YARR_JIT_START,
js::TraceLogging::YARR_JIT_STOP);
#endif
YarrJITCode16 fn = JS_FUNC_TO_DATA_PTR(YarrJITCode16, m_ref16.code().executableAddress());
return MatchResult(CALL_GENERATED_YARR_CODE4(fn, input, start, length, output));
}
@ -140,12 +118,6 @@ public:
{
ASSERT(has16BitCodeMatchOnly());
#if JS_TRACE_LOGGING
js::AutoTraceLog logger(js::TraceLogging::defaultLogger(),
js::TraceLogging::YARR_JIT_START,
js::TraceLogging::YARR_JIT_STOP);
#endif
YarrJITCodeMatchOnly16 fn = JS_FUNC_TO_DATA_PTR(YarrJITCodeMatchOnly16, m_matchOnly16.code().executableAddress());
return MatchResult(CALL_GENERATED_YARR_CODE3(fn, input, start, length));
}