Source code
Revision control
Copy as Markdown
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
#ifdef JS_JITSPEW
# include "jit/JitSpewer.h"
# include "mozilla/Atomics.h"
# include "mozilla/Sprintf.h"
# include "jit/MIR.h"
# include "jit/MIRGenerator.h"
# include "jit/MIRGraph.h"
# include "threading/LockGuard.h"
# include "util/GetPidProvider.h" // getpid()
# include "vm/MutexIDs.h"
# ifndef JIT_SPEW_DIR
# if defined(_WIN32)
# define JIT_SPEW_DIR "."
# elif defined(__ANDROID__)
# define JIT_SPEW_DIR "/data/local/tmp"
# else
# define JIT_SPEW_DIR "/tmp"
# endif
# endif
using namespace js;
using namespace js::jit;
using namespace js::jitspew::detail;
class IonSpewer {
private:
Mutex outputLock_ MOZ_UNANNOTATED;
Fprinter jsonOutput_;
bool firstFunction_;
bool asyncLogging_;
bool inited_;
void release();
public:
IonSpewer()
: outputLock_(mutexid::IonSpewer),
firstFunction_(false),
asyncLogging_(false),
inited_(false) {}
// File output is terminated safely upon destruction.
~IonSpewer();
bool init();
bool isEnabled() { return inited_; }
void setAsyncLogging(bool incremental) { asyncLogging_ = incremental; }
bool getAsyncLogging() { return asyncLogging_; }
void beginFunction();
void spewPass(GraphSpewer* gs);
void endFunction(GraphSpewer* gs);
};
// IonSpewer singleton.
MOZ_RUNINIT static IonSpewer ionspewer;
bool jitspew::detail::LoggingChecked = false;
static_assert(JitSpew_Terminator <= 64,
"Increase the size of the LoggingBits global.");
uint64_t jitspew::detail::LoggingBits = 0;
mozilla::Atomic<uint32_t, mozilla::Relaxed>
jitspew::detail::filteredOutCompilations(0);
static const char* const ChannelNames[] = {
# define JITSPEW_CHANNEL(name) #name,
JITSPEW_CHANNEL_LIST(JITSPEW_CHANNEL)
# undef JITSPEW_CHANNEL
};
static size_t ChannelIndentLevel[] = {
# define JITSPEW_CHANNEL(name) 0,
JITSPEW_CHANNEL_LIST(JITSPEW_CHANNEL)
# undef JITSPEW_CHANNEL
};
// The IONFILTER environment variable specifies an expression to select only
// certain functions for spewing to reduce amount of log data generated.
static const char* gSpewFilter = nullptr;
static bool FilterContainsLocation(JSScript* function) {
// If there is no filter we accept all outputs.
if (!gSpewFilter || !gSpewFilter[0]) {
return true;
}
// Disable wasm output when filter is set.
if (!function) {
return false;
}
const char* filename = function->filename();
const size_t line = function->lineno();
const size_t filelen = strlen(filename);
const char* index = strstr(gSpewFilter, filename);
while (index) {
if (index == gSpewFilter || index[-1] == ',') {
if (index[filelen] == 0 || index[filelen] == ',') {
return true;
}
if (index[filelen] == ':' && line != size_t(-1)) {
size_t read_line = strtoul(&index[filelen + 1], nullptr, 10);
if (read_line == line) {
return true;
}
}
}
index = strstr(index + filelen, filename);
}
return false;
}
void jit::EnableIonDebugSyncLogging() {
ionspewer.init();
ionspewer.setAsyncLogging(false);
EnableChannel(JitSpew_IonSyncLogs);
}
void jit::EnableIonDebugAsyncLogging() {
ionspewer.init();
ionspewer.setAsyncLogging(true);
}
void IonSpewer::release() {
if (jsonOutput_.isInitialized()) {
jsonOutput_.finish();
}
inited_ = false;
}
bool IonSpewer::init() {
if (inited_) {
return true;
}
// Filter expression for spewing
gSpewFilter = getenv("IONFILTER");
const size_t bufferLength = 256;
char jsonBuffer[bufferLength];
const char* jsonFilename = JIT_SPEW_DIR "/ion.json";
const char* usePid = getenv("ION_SPEW_BY_PID");
if (usePid && *usePid != 0) {
uint32_t pid = getpid();
size_t len;
len = SprintfLiteral(jsonBuffer, JIT_SPEW_DIR "/ion%" PRIu32 ".json", pid);
if (bufferLength <= len) {
fprintf(stderr, "Warning: IonSpewer::init: Cannot serialize file name.");
return false;
}
jsonFilename = jsonBuffer;
}
if (!jsonOutput_.init(jsonFilename)) {
release();
return false;
}
jsonOutput_.printf("{\n \"functions\": [\n");
firstFunction_ = true;
inited_ = true;
return true;
}
void IonSpewer::beginFunction() {
// If we are doing a synchronous logging then we spew everything as we go,
// as this is useful in case of failure during the compilation. On the other
// hand, it is recommended to disable off thread compilation.
if (!getAsyncLogging() && !firstFunction_) {
LockGuard<Mutex> guard(outputLock_);
jsonOutput_.put(","); // separate functions
}
}
void IonSpewer::spewPass(GraphSpewer* gs) {
if (!getAsyncLogging()) {
LockGuard<Mutex> guard(outputLock_);
gs->dump(jsonOutput_);
}
}
void IonSpewer::endFunction(GraphSpewer* gs) {
LockGuard<Mutex> guard(outputLock_);
if (getAsyncLogging() && !firstFunction_) {
jsonOutput_.put(","); // separate functions
}
gs->dump(jsonOutput_);
firstFunction_ = false;
}
IonSpewer::~IonSpewer() {
if (!inited_) {
return;
}
jsonOutput_.printf("\n]}\n");
release();
}
GraphSpewer::GraphSpewer(TempAllocator* alloc)
: graph_(nullptr),
jsonPrinter_(alloc->lifoAlloc()),
jsonSpewer_(jsonPrinter_) {}
void GraphSpewer::init(MIRGraph* graph, JSScript* function) {
MOZ_ASSERT(!isSpewing());
if (!ionspewer.isEnabled()) {
return;
}
if (!FilterContainsLocation(function)) {
// filter out logs during the compilation.
filteredOutCompilations++;
MOZ_ASSERT(!isSpewing());
return;
}
graph_ = graph;
MOZ_ASSERT(isSpewing());
}
void GraphSpewer::beginFunction(JSScript* function) {
if (!isSpewing()) {
return;
}
jsonSpewer_.beginFunction(function);
ionspewer.beginFunction();
}
void GraphSpewer::beginWasmFunction(unsigned funcIndex) {
if (!isSpewing()) {
return;
}
jsonSpewer_.beginWasmFunction(funcIndex);
ionspewer.beginFunction();
}
void GraphSpewer::spewPass(const char* pass) {
if (!isSpewing()) {
return;
}
jsonSpewer_.beginPass(pass);
jsonSpewer_.spewMIR(graph_);
jsonSpewer_.spewLIR(graph_);
jsonSpewer_.endPass();
ionspewer.spewPass(this);
// As this function is used for debugging, we ignore any of the previous
// failures and ensure there is enough ballast space, such that we do not
// exhaust the ballast space before running the next phase.
AutoEnterOOMUnsafeRegion oomUnsafe;
if (!graph_->alloc().ensureBallast()) {
oomUnsafe.crash(
"Could not ensure enough ballast space after spewing graph "
"information.");
}
}
void GraphSpewer::spewPass(const char* pass, BacktrackingAllocator* ra) {
if (!isSpewing()) {
return;
}
jsonSpewer_.beginPass(pass);
jsonSpewer_.spewMIR(graph_);
jsonSpewer_.spewLIR(graph_);
jsonSpewer_.spewRanges(ra);
jsonSpewer_.endPass();
ionspewer.spewPass(this);
}
void GraphSpewer::endFunction() {
if (!ionspewer.isEnabled()) {
return;
}
if (!isSpewing()) {
MOZ_ASSERT(filteredOutCompilations != 0);
filteredOutCompilations--;
return;
}
jsonSpewer_.endFunction();
ionspewer.endFunction(this);
graph_ = nullptr;
}
void GraphSpewer::dump(Fprinter& jsonOut) {
if (!jsonPrinter_.hadOutOfMemory()) {
jsonPrinter_.exportInto(jsonOut);
} else {
jsonOut.put("{}");
}
jsonOut.flush();
jsonPrinter_.clear();
}
void jit::SpewBeginFunction(MIRGenerator* mir, JSScript* function) {
MIRGraph* graph = &mir->graph();
mir->graphSpewer().init(graph, function);
mir->graphSpewer().beginFunction(function);
}
void jit::SpewBeginWasmFunction(MIRGenerator* mir, unsigned funcIndex) {
MIRGraph* graph = &mir->graph();
mir->graphSpewer().init(graph, nullptr);
mir->graphSpewer().beginWasmFunction(funcIndex);
}
AutoSpewEndFunction::~AutoSpewEndFunction() {
mir_->graphSpewer().endFunction();
}
Fprinter& jit::JitSpewPrinter() {
static Fprinter out;
return out;
}
static void PrintHelpAndExit(int status = 0) {
fflush(nullptr);
printf(
"\n"
"usage: IONFLAGS=option,option,option,... where options can be:\n"
"\n"
" aborts Compilation abort messages\n"
" scripts Compiled scripts\n"
" mir MIR information\n"
" prune Prune unused branches\n"
" escape Escape analysis\n"
" alias Alias analysis\n"
" alias-sum Alias analysis: shows summaries for every block\n"
" gvn Global Value Numbering\n"
" licm Loop invariant code motion\n"
" flac Fold linear arithmetic constants\n"
" eaa Effective address analysis\n"
" sink Sink transformation\n"
" regalloc Register allocation\n"
" inline Inlining\n"
" snapshots Snapshot information\n"
" codegen Native code generation\n"
" bailouts Bailouts\n"
" caches Inline caches\n"
" osi Invalidation\n"
" safepoints Safepoints\n"
" pools Literal Pools (ARM only for now)\n"
" cacheflush Instruction Cache flushes (ARM only for now)\n"
" range Range Analysis\n"
" branch-hint Wasm Branch Hinting\n"
" wasmbce Wasm Bounds Check Elimination\n"
" shapeguards Redundant shape guard elimination\n"
" gcbarriers Redundant GC barrier elimination\n"
" loadkeys Loads used as property keys\n"
" stubfolding CacheIR stub folding\n"
" logs JSON visualization logging\n"
" logs-sync Same as logs, but flushes between each pass (sync. "
"compiled functions only).\n"
" profiling Profiling-related information\n"
" dump-mir-expr Dump the MIR expressions\n"
" warp-snapshots WarpSnapshots created by WarpOracle\n"
" warp-transpiler Warp CacheIR transpiler\n"
" warp-trial-inlining Trial inlining for Warp\n"
" all Everything\n"
"\n"
" bl-aborts Baseline compiler abort messages\n"
" bl-scripts Baseline script-compilation\n"
" bl-op Baseline compiler detailed op-specific messages\n"
" bl-ic Baseline inline-cache messages\n"
" bl-ic-fb Baseline IC fallback stub messages\n"
" bl-osr Baseline IC OSR messages\n"
" bl-bails Baseline bailouts\n"
" bl-dbg-osr Baseline debug mode on stack recompile messages\n"
" bl-all All baseline spew\n"
"\n"
"See also SPEW=help for information on the Structured Spewer."
"\n");
exit(status);
}
static bool IsFlag(const char* found, const char* flag) {
return strlen(found) == strlen(flag) && strcmp(found, flag) == 0;
}
void jit::CheckLogging() {
if (LoggingChecked) {
return;
}
LoggingChecked = true;
char* env = getenv("IONFLAGS");
if (!env) {
return;
}
const char* found = strtok(env, ",");
while (found) {
fprintf(stderr, "found tag: %s\n", found);
// We're at the end of a flag; check if the previous substring was a
// known flag (i-1 is the last character of the flag we just read).
if (IsFlag(found, "help")) {
PrintHelpAndExit();
} else if (IsFlag(found, "aborts")) {
EnableChannel(JitSpew_IonAbort);
} else if (IsFlag(found, "prune")) {
EnableChannel(JitSpew_Prune);
} else if (IsFlag(found, "escape")) {
EnableChannel(JitSpew_Escape);
} else if (IsFlag(found, "alias")) {
EnableChannel(JitSpew_Alias);
} else if (IsFlag(found, "alias-sum")) {
EnableChannel(JitSpew_AliasSummaries);
} else if (IsFlag(found, "scripts")) {
EnableChannel(JitSpew_IonScripts);
} else if (IsFlag(found, "mir")) {
EnableChannel(JitSpew_IonMIR);
} else if (IsFlag(found, "gvn")) {
EnableChannel(JitSpew_GVN);
} else if (IsFlag(found, "range")) {
EnableChannel(JitSpew_Range);
} else if (IsFlag(found, "wasmbce")) {
EnableChannel(JitSpew_WasmBCE);
} else if (IsFlag(found, "branch-hint")) {
EnableChannel(JitSpew_BranchHint);
} else if (IsFlag(found, "licm")) {
EnableChannel(JitSpew_LICM);
} else if (IsFlag(found, "flac")) {
EnableChannel(JitSpew_FLAC);
} else if (IsFlag(found, "eaa")) {
EnableChannel(JitSpew_EAA);
} else if (IsFlag(found, "sink")) {
EnableChannel(JitSpew_Sink);
} else if (IsFlag(found, "regalloc")) {
EnableChannel(JitSpew_RegAlloc);
} else if (IsFlag(found, "inline")) {
EnableChannel(JitSpew_Inlining);
} else if (IsFlag(found, "snapshots")) {
EnableChannel(JitSpew_IonSnapshots);
} else if (IsFlag(found, "codegen")) {
EnableChannel(JitSpew_Codegen);
} else if (IsFlag(found, "bailouts")) {
EnableChannel(JitSpew_IonBailouts);
} else if (IsFlag(found, "osi")) {
EnableChannel(JitSpew_IonInvalidate);
} else if (IsFlag(found, "caches")) {
EnableChannel(JitSpew_IonIC);
} else if (IsFlag(found, "safepoints")) {
EnableChannel(JitSpew_Safepoints);
} else if (IsFlag(found, "pools")) {
EnableChannel(JitSpew_Pools);
} else if (IsFlag(found, "cacheflush")) {
EnableChannel(JitSpew_CacheFlush);
} else if (IsFlag(found, "shapeguards")) {
EnableChannel(JitSpew_RedundantShapeGuards);
} else if (IsFlag(found, "gcbarriers")) {
EnableChannel(JitSpew_RedundantGCBarriers);
} else if (IsFlag(found, "loadkeys")) {
EnableChannel(JitSpew_MarkLoadsUsedAsPropertyKeys);
} else if (IsFlag(found, "stubfolding")) {
EnableChannel(JitSpew_StubFolding);
} else if (IsFlag(found, "logs")) {
EnableIonDebugAsyncLogging();
} else if (IsFlag(found, "logs-sync")) {
EnableIonDebugSyncLogging();
} else if (IsFlag(found, "profiling")) {
EnableChannel(JitSpew_Profiling);
} else if (IsFlag(found, "dump-mir-expr")) {
EnableChannel(JitSpew_MIRExpressions);
} else if (IsFlag(found, "warp-snapshots")) {
EnableChannel(JitSpew_WarpSnapshots);
} else if (IsFlag(found, "warp-transpiler")) {
EnableChannel(JitSpew_WarpTranspiler);
} else if (IsFlag(found, "warp-trial-inlining")) {
EnableChannel(JitSpew_WarpTrialInlining);
} else if (IsFlag(found, "all")) {
LoggingBits = uint64_t(-1);
} else if (IsFlag(found, "bl-aborts")) {
EnableChannel(JitSpew_BaselineAbort);
} else if (IsFlag(found, "bl-scripts")) {
EnableChannel(JitSpew_BaselineScripts);
} else if (IsFlag(found, "bl-op")) {
EnableChannel(JitSpew_BaselineOp);
} else if (IsFlag(found, "bl-ic")) {
EnableChannel(JitSpew_BaselineIC);
} else if (IsFlag(found, "bl-ic-fb")) {
EnableChannel(JitSpew_BaselineICFallback);
} else if (IsFlag(found, "bl-osr")) {
EnableChannel(JitSpew_BaselineOSR);
} else if (IsFlag(found, "bl-bails")) {
EnableChannel(JitSpew_BaselineBailouts);
} else if (IsFlag(found, "bl-dbg-osr")) {
EnableChannel(JitSpew_BaselineDebugModeOSR);
} else if (IsFlag(found, "bl-all")) {
EnableChannel(JitSpew_BaselineAbort);
EnableChannel(JitSpew_BaselineScripts);
EnableChannel(JitSpew_BaselineOp);
EnableChannel(JitSpew_BaselineIC);
EnableChannel(JitSpew_BaselineICFallback);
EnableChannel(JitSpew_BaselineOSR);
EnableChannel(JitSpew_BaselineBailouts);
EnableChannel(JitSpew_BaselineDebugModeOSR);
} else {
fprintf(stderr, "Unknown flag.\n");
PrintHelpAndExit(64);
}
found = strtok(nullptr, ",");
}
FILE* spewfh = stderr;
const char* filename = getenv("ION_SPEW_FILENAME");
if (filename && *filename) {
char actual_filename[2048] = {0};
SprintfLiteral(actual_filename, "%s.%d", filename, getpid());
spewfh = fopen(actual_filename, "w");
MOZ_RELEASE_ASSERT(spewfh);
setbuf(spewfh, nullptr); // Make unbuffered
}
JitSpewPrinter().init(spewfh);
}
JitSpewIndent::JitSpewIndent(JitSpewChannel channel) : channel_(channel) {
ChannelIndentLevel[channel]++;
}
JitSpewIndent::~JitSpewIndent() { ChannelIndentLevel[channel_]--; }
void jit::JitSpewStartVA(JitSpewChannel channel, const char* fmt, va_list ap) {
if (!JitSpewEnabled(channel)) {
return;
}
JitSpewHeader(channel);
Fprinter& out = JitSpewPrinter();
out.vprintf(fmt, ap);
}
void jit::JitSpewContVA(JitSpewChannel channel, const char* fmt, va_list ap) {
if (!JitSpewEnabled(channel)) {
return;
}
Fprinter& out = JitSpewPrinter();
out.vprintf(fmt, ap);
}
void jit::JitSpewFin(JitSpewChannel channel) {
if (!JitSpewEnabled(channel)) {
return;
}
Fprinter& out = JitSpewPrinter();
out.put("\n");
}
void jit::JitSpewVA(JitSpewChannel channel, const char* fmt, va_list ap) {
JitSpewStartVA(channel, fmt, ap);
JitSpewFin(channel);
}
void jit::JitSpew(JitSpewChannel channel, const char* fmt, ...) {
va_list ap;
va_start(ap, fmt);
JitSpewVA(channel, fmt, ap);
// Suppress hazard analysis on logPrintVA function pointer.
JS::AutoSuppressGCAnalysis suppress;
switch (channel) {
# define SpewChannel(x) \
case JitSpew_##x: \
if (x##Module.shouldLog(mozilla::LogLevel::Debug)) { \
x##Module.interface.logPrintVA(x##Module.logger, \
mozilla::LogLevel::Debug, fmt, ap); \
} \
break;
JITSPEW_CHANNEL_LIST(SpewChannel)
# undef SpewChannel
case JitSpew_Terminator:
MOZ_CRASH("Unexpected JitSpew");
}
va_end(ap);
}
void jit::JitSpewDef(JitSpewChannel channel, const char* str,
MDefinition* def) {
if (!JitSpewEnabled(channel)) {
return;
}
JitSpewHeader(channel);
Fprinter& out = JitSpewPrinter();
out.put(str);
def->dump(out);
def->dumpLocation(out);
}
void jit::JitSpewStart(JitSpewChannel channel, const char* fmt, ...) {
va_list ap;
va_start(ap, fmt);
JitSpewStartVA(channel, fmt, ap);
va_end(ap);
}
void jit::JitSpewCont(JitSpewChannel channel, const char* fmt, ...) {
va_list ap;
va_start(ap, fmt);
JitSpewContVA(channel, fmt, ap);
va_end(ap);
}
void jit::JitSpewHeader(JitSpewChannel channel) {
if (!JitSpewEnabled(channel)) {
return;
}
Fprinter& out = JitSpewPrinter();
out.printf("[%s] ", ChannelNames[channel]);
for (size_t i = ChannelIndentLevel[channel]; i != 0; i--) {
out.put(" ");
}
}
void jit::EnableChannel(JitSpewChannel channel) {
MOZ_ASSERT(LoggingChecked);
LoggingBits |= uint64_t(1) << uint32_t(channel);
}
void jit::DisableChannel(JitSpewChannel channel) {
MOZ_ASSERT(LoggingChecked);
LoggingBits &= ~(uint64_t(1) << uint32_t(channel));
}
const char* js::jit::ValTypeToString(JSValueType type) {
switch (type) {
case JSVAL_TYPE_DOUBLE:
return "Double";
case JSVAL_TYPE_INT32:
return "Int32";
case JSVAL_TYPE_BOOLEAN:
return "Boolean";
case JSVAL_TYPE_UNDEFINED:
return "Undefined";
case JSVAL_TYPE_NULL:
return "Null";
case JSVAL_TYPE_MAGIC:
return "Magic";
case JSVAL_TYPE_STRING:
return "String";
case JSVAL_TYPE_SYMBOL:
return "Symbol";
case JSVAL_TYPE_PRIVATE_GCTHING:
return "PrivateGCThing";
case JSVAL_TYPE_BIGINT:
return "BigInt";
case JSVAL_TYPE_OBJECT:
return "Object";
case JSVAL_TYPE_UNKNOWN:
return "None";
default:
MOZ_CRASH("Unknown JSValueType");
}
}
#endif /* JS_JITSPEW */