Source code

Revision control

Other Tools

/* -*- 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 */