https://github.com/mozilla/gecko-dev
Tip revision: 68bba3abd53ee78d9996e00a47b9d024604d30bf authored by Ryan VanderMeulen on 29 July 2015, 14:12:35 UTC
Added tag B2G_2_0_END for changeset 2e6f1d4deff9 on a CLOSED TREE
Added tag B2G_2_0_END for changeset 2e6f1d4deff9 on a CLOSED TREE
Tip revision: 68bba3a
TraceLogging.h
/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
* vim: set ts=8 sts=4 et sw=4 tw=99:
* This Source Code Form is subject to the terms of the Mozilla Public
* License, v. 2.0. If a copy of the MPL was not distributed with this
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
#ifndef TraceLogging_h
#define TraceLogging_h
#include "jsalloc.h"
#ifdef JS_THREADSAFE
# include "jslock.h"
#endif
#include "mozilla/GuardObjects.h"
#include "js/HashTable.h"
#include "js/TypeDecls.h"
#include "js/Vector.h"
struct JSRuntime;
namespace JS {
class ReadOnlyCompileOptions;
}
namespace js {
class PerThreadData;
namespace jit {
class CompileRuntime;
}
/*
* 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*)
* - TraceLoggerForCurrentThread(); // Should NOT be used for the mainthread.
* 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);
*/
#define TRACELOGGER_TEXT_ID_LIST(_) \
_(Bailout) \
_(Baseline) \
_(BaselineCompilation) \
_(GC) \
_(GCAllocation) \
_(GCSweeping) \
_(Interpreter) \
_(Invalidation) \
_(IonCompilation) \
_(IonLinking) \
_(IonMonkey) \
_(MinorGC) \
_(ParserCompileFunction) \
_(ParserCompileLazy) \
_(ParserCompileScript) \
_(TL) \
_(YarrCompile) \
_(YarrInterpret) \
_(YarrJIT) \
_(IrregexpCompile) \
_(IrregexpExecute) \
_(VM) \
\
/* Specific passes during ion compilation */ \
_(SplitCriticalEdges) \
_(RenumberBlocks) \
_(DominatorTree) \
_(PhiAnalysis) \
_(MakeLoopsContiguous) \
_(ApplyTypes) \
_(ParallelSafetyAnalysis) \
_(AliasAnalysis) \
_(GVN) \
_(UCE) \
_(LICM) \
_(RangeAnalysis) \
_(EffectiveAddressAnalysis) \
_(EliminateDeadCode) \
_(EdgeCaseAnalysis) \
_(EliminateRedundantChecks) \
_(AddKeepAliveInstructions) \
_(GenerateLIR) \
_(RegisterAllocation) \
_(GenerateCode) \
class AutoTraceLog;
template <class T>
class ContinuousSpace {
T* data_;
uint32_t next_;
uint32_t capacity_;
public:
ContinuousSpace ()
: data_(nullptr)
{ }
bool init() {
capacity_ = 64;
next_ = 0;
data_ = (T*) js_malloc(capacity_ * sizeof(T));
if (!data_)
return false;
return true;
}
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() {
MOZ_ASSERT(next_ > 0);
return next_ - 1;
}
T& current() {
return data()[currentId()];
}
bool hasSpaceForAdd(uint32_t count = 1) {
if (next_ + count <= capacity_)
return true;
return false;
}
bool ensureSpaceBeforeAdd(uint32_t count = 1) {
if (hasSpaceForAdd(count))
return true;
uint32_t nCapacity = capacity_ * 2;
if (next_ + count > nCapacity)
nCapacity = next_ + count;
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() {
MOZ_ASSERT(next_ < capacity_);
return data()[next_++];
}
void pop() {
MOZ_ASSERT(next_ > 0);
next_--;
}
void clear() {
next_ = 0;
}
};
class TraceLogger
{
public:
// Predefined IDs for common operations. These IDs can be used
// without using TraceLogCreateTextId, because there are already created.
enum TextId {
TL_Error = 0,
# define DEFINE_TEXT_ID(textId) textId,
TRACELOGGER_TEXT_ID_LIST(DEFINE_TEXT_ID)
# undef DEFINE_TEXT_ID
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)
{
start_ = start;
stop_ = stop;
u.s.textId_ = textId;
u.s.hasChildren_ = hasChildren;
nextId_ = nextId;
}
TreeEntry()
{ }
uint64_t start() {
return start_;
}
uint64_t stop() {
return stop_;
}
uint32_t textId() {
return u.s.textId_;
}
bool hasChildren() {
return u.s.hasChildren_;
}
uint32_t nextId() {
return nextId_;
}
void setStart(uint64_t start) {
start_ = start;
}
void setStop(uint64_t stop) {
stop_ = stop;
}
void setTextId(uint32_t textId) {
MOZ_ASSERT(textId < uint32_t(1<<31) );
u.s.textId_ = textId;
}
void setHasChildren(bool hasChildren) {
u.s.hasChildren_ = hasChildren;
}
void setNextId(uint32_t nextId) {
nextId_ = nextId;
}
};
// Helper structure for keeping track of the current entries in
// the tree. Pushed by `start(id)`, popped by `stop(id)`. The active flag
// is used to know if a subtree doesn't need to get logged.
struct StackEntry {
uint32_t treeId_;
uint32_t lastChildId_;
struct {
uint32_t textId_: 31;
uint32_t active_: 1;
} s;
StackEntry(uint32_t treeId, uint32_t lastChildId, bool active = true)
: treeId_(treeId), lastChildId_(lastChildId)
{
s.textId_ = 0;
s.active_ = active;
}
uint32_t treeId() {
return treeId_;
}
uint32_t lastChildId() {
return lastChildId_;
}
uint32_t textId() {
return s.textId_;
}
bool active() {
return s.active_;
}
void setTreeId(uint32_t treeId) {
treeId_ = treeId;
}
void setLastChildId(uint32_t lastChildId) {
lastChildId_ = lastChildId;
}
void setTextId(uint32_t textId) {
MOZ_ASSERT(textId < uint32_t(1<<31) );
s.textId_ = textId;
}
void setActive(bool active) {
s.active_ = active;
}
};
// 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 enabledTimes;
bool failed;
uint32_t nextTextId;
PointerHashMap pointerMap;
ContinuousSpace<TreeEntry> tree;
ContinuousSpace<StackEntry> stack;
ContinuousSpace<EventEntry> events;
uint32_t treeOffset;
public:
AutoTraceLog* top;
private:
// Helper functions that convert a TreeEntry in different endianness
// in place.
void entryToBigEndian(TreeEntry* entry);
void entryToSystemEndian(TreeEntry* entry);
// Helper functions to get/save a tree from file.
bool getTreeEntry(uint32_t treeId, TreeEntry* entry);
bool saveTreeEntry(uint32_t treeId, TreeEntry* entry);
// Return the first StackEntry that is active.
StackEntry& getActiveAncestor();
// This contains the meat of startEvent, except the test for enough space,
// the test if tracelogger is enabled and the timestamp computation.
bool startEvent(uint32_t id, uint64_t timestamp);
// Update functions that can adjust the items in the tree,
// both in memory or already written to disk.
bool updateHasChildren(uint32_t treeId, bool hasChildren = true);
bool updateNextId(uint32_t treeId, uint32_t nextId);
bool updateStop(uint32_t treeId, uint64_t timestamp);
// Flush the tree and events.
bool flush();
public:
TraceLogger();
~TraceLogger();
bool init(uint32_t loggerId);
bool enable();
bool disable();
// 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
#ifdef JS_THREADSAFE
typedef HashMap<PRThread*,
TraceLogger*,
PointerHasher<PRThread*, 3>,
SystemAllocPolicy> ThreadLoggerHashMap;
#endif // JS_THREADSAFE
typedef Vector<TraceLogger*, 1, js::SystemAllocPolicy > MainThreadLoggers;
bool initialized;
bool enabled;
bool enabledTextIds[TraceLogger::LAST];
bool mainThreadEnabled;
bool offThreadEnabled;
#ifdef JS_THREADSAFE
ThreadLoggerHashMap threadLoggers;
#endif // JS_THREADSAFE
MainThreadLoggers mainThreadLoggers;
uint32_t loggerId;
FILE* out;
public:
uint64_t startupTime;
#ifdef JS_THREADSAFE
PRLock* lock;
#endif // JS_THREADSAFE
TraceLogging();
~TraceLogging();
TraceLogger* forMainThread(JSRuntime* runtime);
TraceLogger* forMainThread(jit::CompileRuntime* runtime);
#ifdef JS_THREADSAFE
TraceLogger* forThread(PRThread* thread);
#endif // JS_THREADSAFE
bool isTextIdEnabled(uint32_t textId) {
if (textId < TraceLogger::LAST)
return enabledTextIds[textId];
return true;
}
private:
TraceLogger* forMainThread(PerThreadData* mainThread);
TraceLogger* create();
bool lazyInit();
#endif
};
#ifdef JS_TRACE_LOGGING
TraceLogger* TraceLoggerForMainThread(JSRuntime* runtime);
TraceLogger* TraceLoggerForMainThread(jit::CompileRuntime* runtime);
TraceLogger* TraceLoggerForCurrentThread();
#else
inline TraceLogger* TraceLoggerForMainThread(JSRuntime* runtime) {
return nullptr;
};
inline TraceLogger* TraceLoggerForMainThread(jit::CompileRuntime* runtime) {
return nullptr;
};
inline TraceLogger* TraceLoggerForCurrentThread() {
return nullptr;
};
#endif
inline bool TraceLoggerEnable(TraceLogger* logger) {
#ifdef JS_TRACE_LOGGING
if (logger)
return logger->enable();
#endif
return false;
}
inline bool TraceLoggerDisable(TraceLogger* logger) {
#ifdef JS_TRACE_LOGGING
if (logger)
return logger->disable();
#endif
return false;
}
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;
}
#ifdef JS_TRACE_LOGGING
bool TraceLogTextIdEnabled(uint32_t textId);
#else
inline bool TraceLogTextIdEnabled(uint32_t textId) {
return false;
}
#endif
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),
textId(textId),
executed(false)
{
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
if (logger) {
TraceLogStartEvent(logger, textId);
prev = logger->top;
logger->top = this;
}
}
~AutoTraceLog()
{
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
};
#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 // JS_THREADSAFE
}
~AutoTraceLoggingLock() {
#ifdef JS_THREADSAFE
PR_Unlock(logging->lock);
#endif // JS_THREADSAFE
}
private:
MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
};
#endif
} /* namedata js */
#endif /* TraceLogging_h */