michael@0: /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*- michael@0: * vim: set ts=8 sts=4 et sw=4 tw=99: michael@0: * This Source Code Form is subject to the terms of the Mozilla Public michael@0: * License, v. 2.0. If a copy of the MPL was not distributed with this michael@0: * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ michael@0: michael@0: #ifndef TraceLogging_h michael@0: #define TraceLogging_h michael@0: michael@0: #include "jsalloc.h" michael@0: #ifdef JS_THREADSAFE michael@0: # include "jslock.h" michael@0: #endif michael@0: michael@0: #include "mozilla/GuardObjects.h" michael@0: michael@0: #include "js/HashTable.h" michael@0: #include "js/TypeDecls.h" michael@0: #include "js/Vector.h" michael@0: michael@0: struct JSRuntime; michael@0: michael@0: namespace JS { michael@0: class ReadOnlyCompileOptions; michael@0: } michael@0: michael@0: namespace js { michael@0: class PerThreadData; michael@0: michael@0: namespace jit { michael@0: class CompileRuntime; michael@0: } michael@0: michael@0: /* michael@0: * Tracelogging overview. michael@0: * michael@0: * Tracelogging makes it possible to trace the timestamp of a single event and/or michael@0: * the duration of an event. This is implemented to give an as low overhead as michael@0: * possible so it doesn't interfere with running. michael@0: * michael@0: * The output of a tracelogging session is saved in /tmp/tl-data.json. michael@0: * The format of that file is a JS array per tracelogger (=thread), with a map michael@0: * containing: michael@0: * - dict: Name of the file containing a json table with the log text. michael@0: * All other files only contain a index to this table when logging. michael@0: * - events: Name of the file containing a flat list of log events saved michael@0: * in binary format. michael@0: * (64bit: Time Stamp Counter, 32bit index to dict) michael@0: * - tree: Name of the file containing the events with duration. The content michael@0: * is already in a tree data structure. This is also saved in a michael@0: * binary file. michael@0: * - treeFormat: The format used to encode the tree. By default "64,64,31,1,32". michael@0: * There are currently no other formats to save the tree. michael@0: * - 64,64,31,1,31 signifies how many bytes are used for the different michael@0: * parts of the tree. michael@0: * => 64 bits: Time Stamp Counter of start of event. michael@0: * => 64 bits: Time Stamp Counter of end of event. michael@0: * => 31 bits: Index to dict file containing the log text. michael@0: * => 1 bit: Boolean signifying if this entry has children. michael@0: * When true, the child can be found just behind this entry. michael@0: * => 32 bits: Containing the ID of the next event on the same depth michael@0: * or 0 if there isn't an event on the same depth anymore. michael@0: * michael@0: * /-> The position in the file. Id is this divided by size of entry. michael@0: * | So in this case this would be 1 (192bits per entry). michael@0: * | /-> Indicates there are children. The michael@0: * | | first child is located at current michael@0: * | | ID + 1. So 1 + 1 in this case: 2. michael@0: * | | Or 0x00180 in the tree file. michael@0: * | | /-> Next event on the same depth is michael@0: * | | | located at 4. So 0x00300 in the michael@0: * | | | tree file. michael@0: * 0x0000C0: [start, end, dictId, 1, 4] michael@0: * michael@0: * michael@0: * Example: michael@0: * 0x0: [start, end, dictId, 1, 0] michael@0: * | michael@0: * /----------------------------------\ michael@0: * | | michael@0: * 0xC0: [start, end, dictId, 0, 2] 0x180 [start, end, dictId, 1, 0] michael@0: * | michael@0: * /----------------------------------\ michael@0: * | | michael@0: * 0x240: [start, end, dictId, 0, 4] 0x300 [start, end, dictId, 0, 0] michael@0: * michael@0: * michael@0: * Logging something is done in 3 stages. michael@0: * 1) Get the tracelogger of the current thread. michael@0: * - TraceLoggerForMainThread(JSRuntime *) michael@0: * - TraceLoggerForCurrentThread(); // Should NOT be used for the mainthread. michael@0: * 2) Optionally create a textId for the text that needs to get logged. This michael@0: * step takes some time, so try to do this beforehand, outside the hot michael@0: * path and don't do unnecessary repetitions, since it will criple michael@0: * performance. michael@0: * - TraceLogCreateTextId(logger, ...); michael@0: * michael@0: * There are also some text IDs created beforehand. They are located in michael@0: * Tracelogger::TextId. michael@0: * 3) Log the timestamp of an event: michael@0: * - TraceLogTimestamp(logger, textId); michael@0: * michael@0: * or the duration: michael@0: * - TraceLogStartEvent(logger, textId); michael@0: * - TraceLogStopEvent(logger, textId); michael@0: * michael@0: * or the duration with a RAII class: michael@0: * - AutoTraceLog logger(logger, textId); michael@0: */ michael@0: michael@0: #define TRACELOGGER_TEXT_ID_LIST(_) \ michael@0: _(Bailout) \ michael@0: _(Baseline) \ michael@0: _(BaselineCompilation) \ michael@0: _(GC) \ michael@0: _(GCAllocation) \ michael@0: _(GCSweeping) \ michael@0: _(Interpreter) \ michael@0: _(Invalidation) \ michael@0: _(IonCompilation) \ michael@0: _(IonLinking) \ michael@0: _(IonMonkey) \ michael@0: _(MinorGC) \ michael@0: _(ParserCompileFunction) \ michael@0: _(ParserCompileLazy) \ michael@0: _(ParserCompileScript) \ michael@0: _(TL) \ michael@0: _(YarrCompile) \ michael@0: _(YarrInterpret) \ michael@0: _(YarrJIT) \ michael@0: _(VM) \ michael@0: \ michael@0: /* Specific passes during ion compilation */ \ michael@0: _(SplitCriticalEdges) \ michael@0: _(RenumberBlocks) \ michael@0: _(DominatorTree) \ michael@0: _(PhiAnalysis) \ michael@0: _(ApplyTypes) \ michael@0: _(ParallelSafetyAnalysis) \ michael@0: _(AliasAnalysis) \ michael@0: _(GVN) \ michael@0: _(UCE) \ michael@0: _(LICM) \ michael@0: _(RangeAnalysis) \ michael@0: _(EffectiveAddressAnalysis) \ michael@0: _(EliminateDeadCode) \ michael@0: _(EdgeCaseAnalysis) \ michael@0: _(EliminateRedundantChecks) michael@0: michael@0: class AutoTraceLog; michael@0: michael@0: template michael@0: class ContinuousSpace { michael@0: T *data_; michael@0: uint32_t next_; michael@0: uint32_t capacity_; michael@0: michael@0: public: michael@0: ContinuousSpace () michael@0: : data_(nullptr) michael@0: { } michael@0: michael@0: bool init() { michael@0: capacity_ = 64; michael@0: next_ = 0; michael@0: data_ = (T *) js_malloc(capacity_ * sizeof(T)); michael@0: if (!data_) michael@0: return false; michael@0: michael@0: return true; michael@0: } michael@0: michael@0: T *data() { michael@0: return data_; michael@0: } michael@0: michael@0: uint32_t capacity() { michael@0: return capacity_; michael@0: } michael@0: michael@0: uint32_t size() { michael@0: return next_; michael@0: } michael@0: michael@0: uint32_t nextId() { michael@0: return next_; michael@0: } michael@0: michael@0: T &next() { michael@0: return data()[next_]; michael@0: } michael@0: michael@0: uint32_t currentId() { michael@0: MOZ_ASSERT(next_ > 0); michael@0: return next_ - 1; michael@0: } michael@0: michael@0: T ¤t() { michael@0: return data()[currentId()]; michael@0: } michael@0: michael@0: bool ensureSpaceBeforeAdd(uint32_t count = 1) { michael@0: if (next_ + count <= capacity_) michael@0: return true; michael@0: michael@0: uint32_t nCapacity = capacity_ * 2; michael@0: if (next_ + count > nCapacity) michael@0: nCapacity = next_ + count; michael@0: T *entries = (T *) js_realloc(data_, nCapacity * sizeof(T)); michael@0: michael@0: if (!entries) michael@0: return false; michael@0: michael@0: data_ = entries; michael@0: capacity_ = nCapacity; michael@0: michael@0: return true; michael@0: } michael@0: michael@0: T &operator[](size_t i) { michael@0: MOZ_ASSERT(i < next_); michael@0: return data()[i]; michael@0: } michael@0: michael@0: void push(T &data) { michael@0: MOZ_ASSERT(next_ < capacity_); michael@0: data()[next_++] = data; michael@0: } michael@0: michael@0: T &pushUninitialized() { michael@0: MOZ_ASSERT(next_ < capacity_); michael@0: return data()[next_++]; michael@0: } michael@0: michael@0: void pop() { michael@0: MOZ_ASSERT(next_ > 0); michael@0: next_--; michael@0: } michael@0: michael@0: void clear() { michael@0: next_ = 0; michael@0: } michael@0: }; michael@0: michael@0: class TraceLogger michael@0: { michael@0: public: michael@0: // Predefined IDs for common operations. These IDs can be used michael@0: // without using TraceLogCreateTextId, because there are already created. michael@0: enum TextId { michael@0: TL_Error = 0, michael@0: # define DEFINE_TEXT_ID(textId) textId, michael@0: TRACELOGGER_TEXT_ID_LIST(DEFINE_TEXT_ID) michael@0: # undef DEFINE_TEXT_ID michael@0: LAST michael@0: }; michael@0: michael@0: #ifdef JS_TRACE_LOGGING michael@0: private: michael@0: typedef HashMap, michael@0: SystemAllocPolicy> PointerHashMap; michael@0: michael@0: // The layout of the tree in memory and in the log file. Readable by JS michael@0: // using TypedArrays. michael@0: struct TreeEntry { michael@0: uint64_t start_; michael@0: uint64_t stop_; michael@0: union { michael@0: struct { michael@0: uint32_t textId_: 31; michael@0: uint32_t hasChildren_: 1; michael@0: } s; michael@0: uint32_t value_; michael@0: } u; michael@0: uint32_t nextId_; michael@0: michael@0: TreeEntry(uint64_t start, uint64_t stop, uint32_t textId, bool hasChildren, michael@0: uint32_t nextId) michael@0: { michael@0: start_ = start; michael@0: stop_ = stop; michael@0: u.s.textId_ = textId; michael@0: u.s.hasChildren_ = hasChildren; michael@0: nextId_ = nextId; michael@0: } michael@0: TreeEntry() michael@0: { } michael@0: uint64_t start() { michael@0: return start_; michael@0: } michael@0: uint64_t stop() { michael@0: return stop_; michael@0: } michael@0: uint32_t textId() { michael@0: return u.s.textId_; michael@0: } michael@0: bool hasChildren() { michael@0: return u.s.hasChildren_; michael@0: } michael@0: uint32_t nextId() { michael@0: return nextId_; michael@0: } michael@0: void setStart(uint64_t start) { michael@0: start_ = start; michael@0: } michael@0: void setStop(uint64_t stop) { michael@0: stop_ = stop; michael@0: } michael@0: void setTextId(uint32_t textId) { michael@0: MOZ_ASSERT(textId < uint32_t(1<<31) ); michael@0: u.s.textId_ = textId; michael@0: } michael@0: void setHasChildren(bool hasChildren) { michael@0: u.s.hasChildren_ = hasChildren; michael@0: } michael@0: void setNextId(uint32_t nextId) { michael@0: nextId_ = nextId; michael@0: } michael@0: }; michael@0: michael@0: // Helper structure for keeping track of the current entries in michael@0: // the tree. Pushed by `start(id)`, popped by `stop(id)`. The active flag michael@0: // is used to know if a subtree doesn't need to get logged. michael@0: struct StackEntry { michael@0: uint32_t treeId_; michael@0: uint32_t lastChildId_; michael@0: struct { michael@0: uint32_t textId_: 31; michael@0: uint32_t active_: 1; michael@0: } s; michael@0: StackEntry(uint32_t treeId, uint32_t lastChildId, bool active = true) michael@0: : treeId_(treeId), lastChildId_(lastChildId) michael@0: { michael@0: s.textId_ = 0; michael@0: s.active_ = active; michael@0: } michael@0: uint32_t treeId() { michael@0: return treeId_; michael@0: } michael@0: uint32_t lastChildId() { michael@0: return lastChildId_; michael@0: } michael@0: uint32_t textId() { michael@0: return s.textId_; michael@0: } michael@0: bool active() { michael@0: return s.active_; michael@0: } michael@0: void setTreeId(uint32_t treeId) { michael@0: treeId_ = treeId; michael@0: } michael@0: void setLastChildId(uint32_t lastChildId) { michael@0: lastChildId_ = lastChildId; michael@0: } michael@0: void setTextId(uint32_t textId) { michael@0: MOZ_ASSERT(textId < uint32_t(1<<31) ); michael@0: s.textId_ = textId; michael@0: } michael@0: void setActive(bool active) { michael@0: s.active_ = active; michael@0: } michael@0: }; michael@0: michael@0: // The layout of the event log in memory and in the log file. michael@0: // Readable by JS using TypedArrays. michael@0: struct EventEntry { michael@0: uint64_t time; michael@0: uint32_t textId; michael@0: EventEntry(uint64_t time, uint32_t textId) michael@0: : time(time), textId(textId) michael@0: { } michael@0: }; michael@0: michael@0: FILE *dictFile; michael@0: FILE *treeFile; michael@0: FILE *eventFile; michael@0: michael@0: bool enabled; michael@0: uint32_t enabledTimes; michael@0: bool failed; michael@0: uint32_t nextTextId; michael@0: michael@0: PointerHashMap pointerMap; michael@0: michael@0: ContinuousSpace tree; michael@0: ContinuousSpace stack; michael@0: ContinuousSpace events; michael@0: michael@0: uint32_t treeOffset; michael@0: michael@0: public: michael@0: AutoTraceLog *top; michael@0: michael@0: private: michael@0: // Helper functions that convert a TreeEntry in different endianness michael@0: // in place. michael@0: void entryToBigEndian(TreeEntry *entry); michael@0: void entryToSystemEndian(TreeEntry *entry); michael@0: michael@0: // Helper functions to get/save a tree from file. michael@0: bool getTreeEntry(uint32_t treeId, TreeEntry *entry); michael@0: bool saveTreeEntry(uint32_t treeId, TreeEntry *entry); michael@0: michael@0: // Return the first StackEntry that is active. michael@0: StackEntry &getActiveAncestor(); michael@0: michael@0: // This contains the meat of startEvent, except the test for enough space, michael@0: // the test if tracelogger is enabled and the timestamp computation. michael@0: bool startEvent(uint32_t id, uint64_t timestamp); michael@0: michael@0: // Update functions that can adjust the items in the tree, michael@0: // both in memory or already written to disk. michael@0: bool updateHasChildren(uint32_t treeId, bool hasChildren = true); michael@0: bool updateNextId(uint32_t treeId, uint32_t nextId); michael@0: bool updateStop(uint32_t treeId, uint64_t timestamp); michael@0: michael@0: // Flush the tree and events. michael@0: bool flush(); michael@0: michael@0: public: michael@0: TraceLogger(); michael@0: ~TraceLogger(); michael@0: michael@0: bool init(uint32_t loggerId); michael@0: michael@0: bool enable(); michael@0: bool disable(); michael@0: michael@0: // The createTextId functions map a unique input to a logger ID. michael@0: // This ID can be used to log something. Calls to these functions should be michael@0: // limited if possible, because of the overhead. michael@0: uint32_t createTextId(const char *text); michael@0: uint32_t createTextId(JSScript *script); michael@0: uint32_t createTextId(const JS::ReadOnlyCompileOptions &script); michael@0: michael@0: // Log an event (no start/stop, only the timestamp is recorded). michael@0: void logTimestamp(uint32_t id); michael@0: michael@0: // Record timestamps for start and stop of an event. michael@0: // In the stop method, the ID is only used in debug builds to test michael@0: // correctness. michael@0: void startEvent(uint32_t id); michael@0: void stopEvent(uint32_t id); michael@0: void stopEvent(); michael@0: michael@0: private: michael@0: void assertNoQuotes(const char *text) { michael@0: #ifdef DEBUG michael@0: const char *quote = strchr(text, '"'); michael@0: MOZ_ASSERT(!quote); michael@0: #endif michael@0: } michael@0: #endif michael@0: }; michael@0: michael@0: class TraceLogging michael@0: { michael@0: #ifdef JS_TRACE_LOGGING michael@0: #ifdef JS_THREADSAFE michael@0: typedef HashMap, michael@0: SystemAllocPolicy> ThreadLoggerHashMap; michael@0: #endif // JS_THREADSAFE michael@0: typedef Vector MainThreadLoggers; michael@0: michael@0: bool initialized; michael@0: bool enabled; michael@0: bool enabledTextIds[TraceLogger::LAST]; michael@0: bool mainThreadEnabled; michael@0: bool offThreadEnabled; michael@0: #ifdef JS_THREADSAFE michael@0: ThreadLoggerHashMap threadLoggers; michael@0: #endif // JS_THREADSAFE michael@0: MainThreadLoggers mainThreadLoggers; michael@0: uint32_t loggerId; michael@0: FILE *out; michael@0: michael@0: public: michael@0: uint64_t startupTime; michael@0: #ifdef JS_THREADSAFE michael@0: PRLock *lock; michael@0: #endif // JS_THREADSAFE michael@0: michael@0: TraceLogging(); michael@0: ~TraceLogging(); michael@0: michael@0: TraceLogger *forMainThread(JSRuntime *runtime); michael@0: TraceLogger *forMainThread(jit::CompileRuntime *runtime); michael@0: #ifdef JS_THREADSAFE michael@0: TraceLogger *forThread(PRThread *thread); michael@0: #endif // JS_THREADSAFE michael@0: michael@0: bool isTextIdEnabled(uint32_t textId) { michael@0: if (textId < TraceLogger::LAST) michael@0: return enabledTextIds[textId]; michael@0: return true; michael@0: } michael@0: michael@0: private: michael@0: TraceLogger *forMainThread(PerThreadData *mainThread); michael@0: TraceLogger *create(); michael@0: bool lazyInit(); michael@0: #endif michael@0: }; michael@0: michael@0: #ifdef JS_TRACE_LOGGING michael@0: TraceLogger *TraceLoggerForMainThread(JSRuntime *runtime); michael@0: TraceLogger *TraceLoggerForMainThread(jit::CompileRuntime *runtime); michael@0: TraceLogger *TraceLoggerForCurrentThread(); michael@0: #else michael@0: inline TraceLogger *TraceLoggerForMainThread(JSRuntime *runtime) { michael@0: return nullptr; michael@0: }; michael@0: inline TraceLogger *TraceLoggerForMainThread(jit::CompileRuntime *runtime) { michael@0: return nullptr; michael@0: }; michael@0: inline TraceLogger *TraceLoggerForCurrentThread() { michael@0: return nullptr; michael@0: }; michael@0: #endif michael@0: michael@0: inline bool TraceLoggerEnable(TraceLogger *logger) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: return logger->enable(); michael@0: #endif michael@0: return false; michael@0: } michael@0: inline bool TraceLoggerDisable(TraceLogger *logger) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: return logger->disable(); michael@0: #endif michael@0: return false; michael@0: } michael@0: michael@0: inline uint32_t TraceLogCreateTextId(TraceLogger *logger, JSScript *script) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: return logger->createTextId(script); michael@0: #endif michael@0: return TraceLogger::TL_Error; michael@0: } michael@0: inline uint32_t TraceLogCreateTextId(TraceLogger *logger, michael@0: const JS::ReadOnlyCompileOptions &compileOptions) michael@0: { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: return logger->createTextId(compileOptions); michael@0: #endif michael@0: return TraceLogger::TL_Error; michael@0: } michael@0: inline uint32_t TraceLogCreateTextId(TraceLogger *logger, const char *text) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: return logger->createTextId(text); michael@0: #endif michael@0: return TraceLogger::TL_Error; michael@0: } michael@0: #ifdef JS_TRACE_LOGGING michael@0: bool TraceLogTextIdEnabled(uint32_t textId); michael@0: #else michael@0: inline bool TraceLogTextIdEnabled(uint32_t textId) { michael@0: return false; michael@0: } michael@0: #endif michael@0: inline void TraceLogTimestamp(TraceLogger *logger, uint32_t textId) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: logger->logTimestamp(textId); michael@0: #endif michael@0: } michael@0: inline void TraceLogStartEvent(TraceLogger *logger, uint32_t textId) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: logger->startEvent(textId); michael@0: #endif michael@0: } michael@0: inline void TraceLogStopEvent(TraceLogger *logger, uint32_t textId) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: logger->stopEvent(textId); michael@0: #endif michael@0: } michael@0: inline void TraceLogStopEvent(TraceLogger *logger) { michael@0: #ifdef JS_TRACE_LOGGING michael@0: if (logger) michael@0: logger->stopEvent(); michael@0: #endif michael@0: } michael@0: michael@0: // Automatic logging at the start and end of function call. michael@0: class AutoTraceLog { michael@0: #ifdef JS_TRACE_LOGGING michael@0: TraceLogger *logger; michael@0: uint32_t textId; michael@0: bool executed; michael@0: AutoTraceLog *prev; michael@0: michael@0: public: michael@0: AutoTraceLog(TraceLogger *logger, uint32_t textId MOZ_GUARD_OBJECT_NOTIFIER_PARAM) michael@0: : logger(logger), michael@0: textId(textId), michael@0: executed(false) michael@0: { michael@0: MOZ_GUARD_OBJECT_NOTIFIER_INIT; michael@0: if (logger) { michael@0: TraceLogStartEvent(logger, textId); michael@0: michael@0: prev = logger->top; michael@0: logger->top = this; michael@0: } michael@0: } michael@0: michael@0: ~AutoTraceLog() michael@0: { michael@0: if (logger) { michael@0: while (this != logger->top) michael@0: logger->top->stop(); michael@0: stop(); michael@0: } michael@0: } michael@0: private: michael@0: void stop() { michael@0: if (!executed) { michael@0: executed = true; michael@0: TraceLogStopEvent(logger, textId); michael@0: } michael@0: michael@0: if (logger->top == this) michael@0: logger->top = prev; michael@0: } michael@0: #else michael@0: public: michael@0: AutoTraceLog(TraceLogger *logger, uint32_t textId MOZ_GUARD_OBJECT_NOTIFIER_PARAM) michael@0: { michael@0: MOZ_GUARD_OBJECT_NOTIFIER_INIT; michael@0: } michael@0: #endif michael@0: michael@0: private: michael@0: MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER michael@0: }; michael@0: michael@0: #ifdef JS_TRACE_LOGGING michael@0: class AutoTraceLoggingLock michael@0: { michael@0: TraceLogging *logging; michael@0: michael@0: public: michael@0: AutoTraceLoggingLock(TraceLogging *logging MOZ_GUARD_OBJECT_NOTIFIER_PARAM) michael@0: : logging(logging) michael@0: { michael@0: MOZ_GUARD_OBJECT_NOTIFIER_INIT; michael@0: #ifdef JS_THREADSAFE michael@0: PR_Lock(logging->lock); michael@0: #endif // JS_THREADSAFE michael@0: } michael@0: ~AutoTraceLoggingLock() { michael@0: #ifdef JS_THREADSAFE michael@0: PR_Unlock(logging->lock); michael@0: #endif // JS_THREADSAFE michael@0: } michael@0: private: michael@0: MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER michael@0: }; michael@0: #endif michael@0: michael@0: } /* namedata js */ michael@0: michael@0: #endif /* TraceLogging_h */