diff options
Diffstat (limited to 'js/src/vm/TraceLogging.h')
-rw-r--r-- | js/src/vm/TraceLogging.h | 708 |
1 files changed, 708 insertions, 0 deletions
diff --git a/js/src/vm/TraceLogging.h b/js/src/vm/TraceLogging.h new file mode 100644 index 0000000000..1e3a8a08aa --- /dev/null +++ b/js/src/vm/TraceLogging.h @@ -0,0 +1,708 @@ +/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- + * vim: set ts=8 sts=2 et sw=2 tw=80: + * This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +#ifndef TraceLogging_h +#define TraceLogging_h + +#include "mozilla/LinkedList.h" +#include "mozilla/Maybe.h" +#include "mozilla/MemoryReporting.h" +#include "mozilla/Vector.h" + +#include <utility> + +#include "jsapi.h" +#include "jsfriendapi.h" + +#include "js/AllocPolicy.h" +#include "js/friend/ErrorMessages.h" // js::GetErrorMessage, JSMSG_* +#include "js/HashTable.h" +#include "js/TraceLoggerAPI.h" +#include "js/TypeDecls.h" +#include "js/Utility.h" +#include "js/Vector.h" +#include "threading/LockGuard.h" +#include "vm/MutexIDs.h" +#include "vm/TraceLoggingGraph.h" +#include "vm/TraceLoggingTypes.h" + +namespace js { + +namespace jit { +class CompileRuntime; +} // namespace jit + +/* + * [SMDOC] Tracelogging overview. + * + * Tracelogging makes it possible to trace the occurrence of a single event + * and/or the start and stop of an event. This is implemented with as low + * overhead as possible to not interfere with running. + * + * Logging something is done in 3 stages. + * 1) Get the tracelogger of the current thread. cx may be omitted, in which + * case it will be fetched from TLS. + * - TraceLoggerForCurrentThread(cx); + * + * 2) Optionally create a TraceLoggerEvent 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 cripple + * performance. + * - TraceLoggerEvent event(logger, "foo"); + * + * There are also some predefined events. They are located in + * TraceLoggerTextId. They don't require to create an TraceLoggerEvent and + * can also be used as an argument to these functions. + * + * 3) Log the occurrence of a single event: + * - TraceLogTimestamp(logger, TraceLoggerTextId); + * Note: it is temporarily not supported to provide an TraceLoggerEvent as + * argument to log the occurrence of a single event. + * + * or log the start and stop of an event: + * - TraceLogStartEvent(logger, TraceLoggerTextId); + * - TraceLogStartEvent(logger, TraceLoggerEvent); + * - TraceLogStopEvent(logger, TraceLoggerTextId); + * - TraceLogStopEvent(logger, TraceLoggerEvent); + * + * or the start/stop of an event with a RAII class: + * - AutoTraceLog atl(logger, TraceLoggerTextId); + * - AutoTraceLog atl(logger, TraceLoggerEvent); + */ + +class AutoTraceLog; +class TraceLoggerEventPayload; +class TraceLoggerThread; + +/** + * An event that can be used to report start/stop events to TraceLogger. It + * prepares the given info by requesting a TraceLoggerEventPayload containing + * the string to report and an unique id. It also increases the useCount of + * this payload, so it cannot get removed. + */ +class TraceLoggerEvent { +#ifdef JS_TRACE_LOGGING + private: + class EventPayloadOrTextId { + /** + * Payload can be a pointer to a TraceLoggerEventPayload* or a + * TraceLoggerTextId. The last bit decides how to read the payload. + * + * payload_ = [ | 0 ] + * ----------------------- + * TraceLoggerEventPayload* (incl. last bit) + * + * payload_ = [ | 1 ] + * ------------------- + * TraceLoggerTextId (excl. last bit) + */ + uintptr_t payload_; + + public: + EventPayloadOrTextId() : payload_(0) {} + + bool isEventPayload() const { return (payload_ & 1) == 0; } + TraceLoggerEventPayload* eventPayload() const { + MOZ_ASSERT(isEventPayload()); + return (TraceLoggerEventPayload*)payload_; + } + void setEventPayload(TraceLoggerEventPayload* payload) { + MOZ_ASSERT(payload); + payload_ = (uintptr_t)payload; + MOZ_ASSERT((payload_ & 1) == 0); + } + bool isTextId() const { return (payload_ & 1) == 1; } + uint32_t textId() const { + MOZ_ASSERT(isTextId()); + return payload_ >> 1; + } + void setTextId(TraceLoggerTextId textId) { + static_assert(TraceLogger_Last < (UINT32_MAX >> 1), + "Too many predefined text ids."); + payload_ = (((uint32_t)textId) << 1) | 1; + } + }; + + EventPayloadOrTextId payload_; + + public: + TraceLoggerEvent() : payload_() {} + explicit TraceLoggerEvent(TraceLoggerTextId textId); + TraceLoggerEvent(TraceLoggerTextId type, JSScript* script); + TraceLoggerEvent(TraceLoggerTextId type, const char* filename, uint32_t line, + uint32_t column); + explicit TraceLoggerEvent(const char* text); + TraceLoggerEvent(const TraceLoggerEvent& event); + TraceLoggerEvent& operator=(const TraceLoggerEvent& other); + ~TraceLoggerEvent(); + uint32_t textId() const; + bool hasTextId() const { return hasExtPayload() || payload_.isTextId(); } + + private: + TraceLoggerEventPayload* extPayload() const { + MOZ_ASSERT(hasExtPayload()); + return payload_.eventPayload(); + } + bool hasExtPayload() const { + return payload_.isEventPayload() && !!payload_.eventPayload(); + } +#else + public: + TraceLoggerEvent() {} + explicit TraceLoggerEvent(TraceLoggerTextId textId) {} + TraceLoggerEvent(TraceLoggerTextId type, JSScript* script) {} + TraceLoggerEvent(TraceLoggerTextId type, const char* filename, uint32_t line, + uint32_t column) {} + explicit TraceLoggerEvent(const char* text) {} + TraceLoggerEvent(const TraceLoggerEvent& event) {} + TraceLoggerEvent& operator=(const TraceLoggerEvent& other) { return *this; }; + ~TraceLoggerEvent() {} + uint32_t textId() const { return 0; } + bool hasTextId() const { return false; } +#endif +}; + +#ifdef DEBUG +void AssertCurrentThreadOwnsTraceLoggerThreadStateLock(); +#endif + +/** + * An internal class holding the string information to report, together with an + * unique id, and an useCount. Whenever this useCount reaches 0, this event + * cannot get started/stopped anymore. Consumers may still request the + * string information through maybeEventText below, but this may not succeed: + * when the use count becomes zero, a payload may be deleted by any thread + * holding the TraceLoggerThreadState lock, after that the pointers have been + * cleared out of the dictionaryVector. + */ +class TraceLoggerEventPayload { + uint32_t textId_; + uint32_t dictionaryId_; + mozilla::Maybe<uint32_t> line_; + mozilla::Maybe<uint32_t> col_; + mozilla::Atomic<uint32_t> uses_; + + public: + TraceLoggerEventPayload(uint32_t textId, uint32_t dictionaryId) + : textId_(textId), + dictionaryId_(dictionaryId), + line_(mozilla::Nothing()), + col_(mozilla::Nothing()), + uses_(0) {} + + ~TraceLoggerEventPayload() { MOZ_ASSERT(uses_ == 0); } + + void setLine(uint32_t line) { line_ = mozilla::Some(line); } + void setColumn(uint32_t col) { col_ = mozilla::Some(col); } + + mozilla::Maybe<uint32_t> line() { return line_; } + mozilla::Maybe<uint32_t> column() { return col_; } + uint32_t textId() { return textId_; } + uint32_t dictionaryId() { return dictionaryId_; } + void setDictionaryId(uint32_t dictId) { dictionaryId_ = dictId; } + uint32_t uses() { return uses_; } + + // Payloads may have their use count change at any time, *except* the count + // can only go from zero to non-zero while the thread state lock is held. + // This should only happen under getOrCreateEventPayload below, and avoids + // races with purgeUnusedPayloads. + void use() { +#ifdef DEBUG + if (!uses_) { + AssertCurrentThreadOwnsTraceLoggerThreadStateLock(); + } +#endif + uses_++; + } + void release() { uses_--; } + size_t sizeOfIncludingThis(mozilla::MallocSizeOf mallocSizeOf) const { + return mallocSizeOf(this); + } +}; + +// Data structures used to collect per function statistics for spewing +struct ScriptStats { + struct EventData { + uint32_t time; + uint32_t count; + }; + + EventData events_[TraceLogger_Last]; + + char* scriptName; + uint32_t selfTime; + + explicit ScriptStats(char* scriptName_) + : scriptName(scriptName_), selfTime(0) { + for (EventData& entry : events_) { + entry.time = 0; + entry.count = 0; + } + } + + ~ScriptStats() { + JS::FreePolicy freePolicy; + freePolicy(scriptName); + } +}; + +typedef HashMap<char*, UniquePtr<ScriptStats>, mozilla::CStringHasher, + SystemAllocPolicy> + ScriptMap; + +typedef Vector<UniquePtr<ScriptStats>, 0, SystemAllocPolicy> SortedStatsVector; +typedef Vector<uint32_t, 0, js::SystemAllocPolicy> EventVector; + +// Per thread trace logger state. +class TraceLoggerThread : public mozilla::LinkedListElement<TraceLoggerThread> { +#ifdef JS_TRACE_LOGGING + friend JS::TraceLoggerIdImpl; + friend JS::TraceLoggerTimeStampImpl; + friend JS::TraceLoggerDurationImpl; + friend JS::TraceLoggerLineNoImpl; + friend JS::TraceLoggerColNoImpl; + + private: + JSContext* cx_; + uint32_t enabled_ = 0; + bool failed_ = false; + + UniquePtr<TraceLoggerGraph> graph_; + ContinuousSpace<EventEntry> events_; + + // Every time the events get flushed, this count is increased by one. + // Together with events.lastEntryId(), this gives an unique id for every + // event. + uint32_t iteration_ = 0; + +# ifdef DEBUG + EventVector graphStack_; +# endif + + JS::UniqueChars threadName_ = nullptr; + + public: + AutoTraceLog* top_ = nullptr; + + explicit TraceLoggerThread(JSContext* cx) : cx_(cx) {} + + bool init(); + ~TraceLoggerThread(); + + bool init(uint32_t loggerId); + void initGraph(); + + void clear(); + + bool enable(); + bool enable(JSContext* cx); + bool disable(bool force = false, const char* = ""); + bool enabled() { return enabled_ > 0; } + + void silentFail(const char* error); + + size_t sizeOfExcludingThis(mozilla::MallocSizeOf mallocSizeOf) const; + size_t sizeOfIncludingThis(mozilla::MallocSizeOf mallocSizeOf) const; + + private: + bool fail(JSContext* cx, const char* error); + + public: + // Given the previous iteration and size, return an array of events + // (there could be lost events). At the same time update the iteration and + // size and gives back how many events there are. + EventEntry* getEventsStartingAt(uint32_t* lastIteration, uint32_t* lastSize, + size_t* num) { + EventEntry* start; + if (iteration_ == *lastIteration) { + MOZ_ASSERT(*lastSize <= events_.size()); + *num = events_.size() - *lastSize; + start = events_.data() + *lastSize; + } else { + *num = events_.size(); + start = events_.data(); + } + + getIterationAndSize(lastIteration, lastSize); + return start; + } + + void getIterationAndSize(uint32_t* iteration, uint32_t* size) const { + *iteration = iteration_; + *size = events_.size(); + } + + bool lostEvents(uint32_t lastIteration, uint32_t lastSize) { + // If still logging in the same iteration, there are no lost events. + if (lastIteration == iteration_) { + MOZ_ASSERT(lastSize <= events_.size()); + return false; + } + + // If we are in the next consecutive iteration we are only sure we + // didn't lose any events when the lastSize equals the maximum size + // 'events' can get. + if (lastIteration == iteration_ - 1 && lastSize == events_.maxSize()) { + return false; + } + + return true; + } + + bool collectTraceLoggerStats(ScriptMap& map); + bool sortTraceLoggerStats(ScriptMap& map, SortedStatsVector& sorted_map); + void spewTraceLoggerStats(); + + private: + const char* maybeEventText(uint32_t id); + + public: + const char* eventText(uint32_t id) { + const char* text = maybeEventText(id); + MOZ_ASSERT(text); + return text; + }; + + public: + // Log an event (no start/stop, only the timestamp is recorded). + void logTimestamp(TraceLoggerTextId id); + + // Record timestamps for start and stop of an event. + void startEvent(TraceLoggerTextId id); + void startEvent(const TraceLoggerEvent& event); + void stopEvent(TraceLoggerTextId id); + void stopEvent(const TraceLoggerEvent& event); + + // These functions are actually private and shouldn't be used in normal + // code. They are made public so they can be used in assembly. + void logTimestamp(uint32_t id); + void startEvent(uint32_t id); + void stopEvent(uint32_t id); + + private: + void stopEvent(); + void log(uint32_t id); + + public: + static unsigned offsetOfEnabled() { + return offsetof(TraceLoggerThread, enabled_); + } +#endif +}; + +// Process wide trace logger state. +class TraceLoggerThreadState { +#ifdef JS_TRACE_LOGGING + friend JS::TraceLoggerDictionaryImpl; +# ifdef DEBUG + bool initialized = false; +# endif + + bool enabledTextIds[TraceLogger_Last]; + bool mainThreadEnabled = false; + bool helperThreadEnabled = false; + bool graphEnabled = false; + bool graphFileEnabled = false; + bool spewErrors = false; + mozilla::LinkedList<TraceLoggerThread> threadLoggers; + + // Any events that carry a payload are saved in this hash map. + // The key is the event textId, and the value is a pointer to + // the payload object. + typedef HashMap<uint32_t, TraceLoggerEventPayload*, DefaultHasher<uint32_t>, + SystemAllocPolicy> + TextIdToPayloadMap; + + // The dictionary vector is used to store all of the custom event strings + // that are referenced by the payload objects. + typedef mozilla::Vector<JS::UniqueChars, 0, SystemAllocPolicy> + DictionaryVector; + + // All payload strings are hashed and saved as a key in the payloadDictionary + // hash table. The values are indices to the dictionaryData vector where the + // actual string is stored. The major benefit of having this hash map is for + // de-duplication of JS script filenames. + typedef HashMap<const char*, uint32_t, mozilla::CStringHasher, + SystemAllocPolicy> + StringHashToDictionaryMap; + + TextIdToPayloadMap textIdPayloads; + StringHashToDictionaryMap payloadDictionary; + DictionaryVector dictionaryData; + + uint32_t nextTextId = TraceLogger_Last; + uint32_t nextDictionaryId = 0; + + public: + mozilla::TimeStamp startTime; + + double getTimeStampOffset(mozilla::TimeStamp time) { + mozilla::TimeDuration delta = time - startTime; + return delta.ToMicroseconds(); + } + + JS::UniqueChars getFullScriptName(uint32_t textId); + + // Mutex to guard the data structures used to hold the payload data: + // textIdPayloads, payloadDictionary & dictionaryData. + Mutex lock; + + TraceLoggerThreadState() : lock(js::mutexid::TraceLoggerThreadState) {} + + bool init(); + ~TraceLoggerThreadState(); + + void enableDefaultLogging(); + void enableIonLogging(); + void enableFrontendLogging(); + + void spewTraceLoggerStats(); + + void clear(); + bool remapDictionaryEntries( + mozilla::Vector<JS::UniqueChars, 0, SystemAllocPolicy>* newDictionary, + uint32_t* newNextDictionaryId); + + TraceLoggerThread* forCurrentThread(JSContext* cx); + void destroyLogger(TraceLoggerThread* logger); + + bool isTextIdEnabled(uint32_t textId) { + if (textId < TraceLogger_Last) { + return enabledTextIds[textId]; + } + return true; + } + void enableTextId(JSContext* cx, uint32_t textId); + void disableTextId(JSContext* cx, uint32_t textId); + void maybeSpewError(const char* text) { + if (spewErrors) { + fprintf(stderr, "%s\n", text); + } + } + + const char* maybeEventText(uint32_t id); + const char* maybeEventText(TraceLoggerEventPayload* p); + + void purgeUnusedPayloads(); + + // These functions map a unique input to a logger ID. + // This can be used to give start and stop events. Calls to these functions + // should be limited if possible, because of the overhead. Note: it is not + // allowed to use them in logTimestamp. + TraceLoggerEventPayload* getOrCreateEventPayload(const char* text); + TraceLoggerEventPayload* getOrCreateEventPayload(JSScript* script); + TraceLoggerEventPayload* getOrCreateEventPayload(const char* filename, + uint32_t lineno, + uint32_t colno); + TraceLoggerEventPayload* getPayload(uint32_t id); + + size_t sizeOfExcludingThis(mozilla::MallocSizeOf mallocSizeOf); + size_t sizeOfIncludingThis(mozilla::MallocSizeOf mallocSizeOf) { + return mallocSizeOf(this) + sizeOfExcludingThis(mallocSizeOf); + } + + bool isGraphFileEnabled() { return graphFileEnabled; } + bool isGraphEnabled() { return graphEnabled; } + + void enableTextIdsForProfiler(); + void disableTextIdsForProfiler(); + void disableAllTextIds(); +#endif +}; + +#ifdef JS_TRACE_LOGGING +void ResetTraceLogger(); +void DestroyTraceLoggerThreadState(); +void DestroyTraceLogger(TraceLoggerThread* logger); + +TraceLoggerThread* TraceLoggerForCurrentThread(JSContext* cx = nullptr); +#else +inline TraceLoggerThread* TraceLoggerForCurrentThread(JSContext* cx = nullptr) { + return nullptr; +}; +#endif + +inline bool TraceLoggerEnable(TraceLoggerThread* logger) { +#ifdef JS_TRACE_LOGGING + if (logger) { + return logger->enable(); + } +#endif + return false; +} +inline bool TraceLoggerEnable(TraceLoggerThread* logger, JSContext* cx) { +#ifdef JS_TRACE_LOGGING + if (logger) { + return logger->enable(cx); + } + JS_ReportErrorNumberASCII(cx, GetErrorMessage, nullptr, + JSMSG_TRACELOGGER_ENABLE_FAIL, "internal error"); +#endif + return false; +} +inline bool TraceLoggerDisable(TraceLoggerThread* logger) { +#ifdef JS_TRACE_LOGGING + if (logger) { + return logger->disable(); + } +#endif + return false; +} +inline void TraceLoggerSilentFail(TraceLoggerThread* logger, + const char* error) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->silentFail(error); + } +#endif +} + +#ifdef JS_TRACE_LOGGING +bool TraceLogTextIdEnabled(uint32_t textId); +void TraceLogEnableTextId(JSContext* cx, uint32_t textId); +void TraceLogDisableTextId(JSContext* cx, uint32_t textId); +#else +inline bool TraceLogTextIdEnabled(uint32_t textId) { return false; } +inline void TraceLogEnableTextId(JSContext* cx, uint32_t textId) {} +inline void TraceLogDisableTextId(JSContext* cx, uint32_t textId) {} +#endif +inline void TraceLogTimestamp(TraceLoggerThread* logger, + TraceLoggerTextId textId) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->logTimestamp(textId); + } +#endif +} +inline void TraceLogStartEvent(TraceLoggerThread* logger, + TraceLoggerTextId textId) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->startEvent(textId); + } +#endif +} +inline void TraceLogStartEvent(TraceLoggerThread* logger, + const TraceLoggerEvent& event) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->startEvent(event); + } +#endif +} +inline void TraceLogStopEvent(TraceLoggerThread* logger, + TraceLoggerTextId textId) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->stopEvent(textId); + } +#endif +} +inline void TraceLogStopEvent(TraceLoggerThread* logger, + const TraceLoggerEvent& event) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->stopEvent(event); + } +#endif +} + +// Helper functions for assembly. May not be used otherwise. +inline void TraceLogTimestampPrivate(TraceLoggerThread* logger, uint32_t id) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->logTimestamp(id); + } +#endif +} +inline void TraceLogStartEventPrivate(TraceLoggerThread* logger, uint32_t id) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->startEvent(id); + } +#endif +} +inline void TraceLogStopEventPrivate(TraceLoggerThread* logger, uint32_t id) { +#ifdef JS_TRACE_LOGGING + if (logger) { + logger->stopEvent(id); + } +#endif +} + +size_t SizeOfTraceLogState(mozilla::MallocSizeOf mallocSizeOf); + +// Automatic logging at the start and end of function call. +class MOZ_RAII AutoTraceLog { +#ifdef JS_TRACE_LOGGING + TraceLoggerThread* logger; + union { + const TraceLoggerEvent* event; + TraceLoggerTextId id; + } payload; + bool isEvent; + bool executed; + AutoTraceLog* prev; + + public: + AutoTraceLog(TraceLoggerThread* logger, const TraceLoggerEvent& event) + : logger(logger), isEvent(true), executed(false), prev(nullptr) { + payload.event = &event; + if (logger) { + logger->startEvent(event); + + prev = logger->top_; + logger->top_ = this; + } + } + + AutoTraceLog(TraceLoggerThread* logger, TraceLoggerTextId id) + : logger(logger), isEvent(false), executed(false), prev(nullptr) { + payload.id = id; + if (logger) { + logger->startEvent(id); + + prev = logger->top_; + logger->top_ = this; + } + } + + ~AutoTraceLog() { + if (logger) { + while (this != logger->top_) { + logger->top_->stop(); + } + stop(); + } + } + + private: + void stop() { + if (!executed) { + executed = true; + if (isEvent) { + logger->stopEvent(*payload.event); + } else { + logger->stopEvent(payload.id); + } + } + + if (logger->top_ == this) { + logger->top_ = prev; + } + } +#else + public: + AutoTraceLog(TraceLoggerThread* logger, uint32_t textId) {} + AutoTraceLog(TraceLoggerThread* logger, const TraceLoggerEvent& event) {} +#endif + + private: +}; + +} // namespace js + +#endif /* TraceLogging_h */ |