Bug 1922904 - Fix bug 1780701 in a different approach. r=botond
[gecko.git] / js / src / jit / JitSpewer.cpp
blobd92e6bf29e6ade84a40e22ad31b5c59856eaa37f
1 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*-
2 * vim: set ts=8 sts=2 et sw=2 tw=80:
3 * This Source Code Form is subject to the terms of the Mozilla Public
4 * License, v. 2.0. If a copy of the MPL was not distributed with this
5 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
7 #ifdef JS_JITSPEW
9 # include "jit/JitSpewer.h"
11 # include "mozilla/Atomics.h"
12 # include "mozilla/Sprintf.h"
14 # include "jit/MIR.h"
15 # include "jit/MIRGenerator.h"
16 # include "jit/MIRGraph.h"
17 # include "threading/LockGuard.h"
18 # include "util/GetPidProvider.h" // getpid()
19 # include "vm/MutexIDs.h"
21 # ifndef JIT_SPEW_DIR
22 # if defined(_WIN32)
23 # define JIT_SPEW_DIR "."
24 # elif defined(__ANDROID__)
25 # define JIT_SPEW_DIR "/data/local/tmp"
26 # else
27 # define JIT_SPEW_DIR "/tmp"
28 # endif
29 # endif
31 using namespace js;
32 using namespace js::jit;
33 using namespace js::jitspew::detail;
35 class IonSpewer {
36 private:
37 Mutex outputLock_ MOZ_UNANNOTATED;
38 Fprinter jsonOutput_;
39 bool firstFunction_;
40 bool asyncLogging_;
41 bool inited_;
43 void release();
45 public:
46 IonSpewer()
47 : outputLock_(mutexid::IonSpewer),
48 firstFunction_(false),
49 asyncLogging_(false),
50 inited_(false) {}
52 // File output is terminated safely upon destruction.
53 ~IonSpewer();
55 bool init();
56 bool isEnabled() { return inited_; }
57 void setAsyncLogging(bool incremental) { asyncLogging_ = incremental; }
58 bool getAsyncLogging() { return asyncLogging_; }
60 void beginFunction();
61 void spewPass(GraphSpewer* gs);
62 void endFunction(GraphSpewer* gs);
65 // IonSpewer singleton.
66 MOZ_RUNINIT static IonSpewer ionspewer;
68 bool jitspew::detail::LoggingChecked = false;
69 static_assert(JitSpew_Terminator <= 64,
70 "Increase the size of the LoggingBits global.");
71 uint64_t jitspew::detail::LoggingBits = 0;
72 mozilla::Atomic<uint32_t, mozilla::Relaxed>
73 jitspew::detail::filteredOutCompilations(0);
75 static const char* const ChannelNames[] = {
76 # define JITSPEW_CHANNEL(name) #name,
77 JITSPEW_CHANNEL_LIST(JITSPEW_CHANNEL)
78 # undef JITSPEW_CHANNEL
81 static size_t ChannelIndentLevel[] = {
82 # define JITSPEW_CHANNEL(name) 0,
83 JITSPEW_CHANNEL_LIST(JITSPEW_CHANNEL)
84 # undef JITSPEW_CHANNEL
87 // The IONFILTER environment variable specifies an expression to select only
88 // certain functions for spewing to reduce amount of log data generated.
89 static const char* gSpewFilter = nullptr;
91 static bool FilterContainsLocation(JSScript* function) {
92 // If there is no filter we accept all outputs.
93 if (!gSpewFilter || !gSpewFilter[0]) {
94 return true;
97 // Disable wasm output when filter is set.
98 if (!function) {
99 return false;
102 const char* filename = function->filename();
103 const size_t line = function->lineno();
104 const size_t filelen = strlen(filename);
105 const char* index = strstr(gSpewFilter, filename);
106 while (index) {
107 if (index == gSpewFilter || index[-1] == ',') {
108 if (index[filelen] == 0 || index[filelen] == ',') {
109 return true;
111 if (index[filelen] == ':' && line != size_t(-1)) {
112 size_t read_line = strtoul(&index[filelen + 1], nullptr, 10);
113 if (read_line == line) {
114 return true;
118 index = strstr(index + filelen, filename);
120 return false;
123 void jit::EnableIonDebugSyncLogging() {
124 ionspewer.init();
125 ionspewer.setAsyncLogging(false);
126 EnableChannel(JitSpew_IonSyncLogs);
129 void jit::EnableIonDebugAsyncLogging() {
130 ionspewer.init();
131 ionspewer.setAsyncLogging(true);
134 void IonSpewer::release() {
135 if (jsonOutput_.isInitialized()) {
136 jsonOutput_.finish();
138 inited_ = false;
141 bool IonSpewer::init() {
142 if (inited_) {
143 return true;
146 // Filter expression for spewing
147 gSpewFilter = getenv("IONFILTER");
149 const size_t bufferLength = 256;
150 char jsonBuffer[bufferLength];
151 const char* jsonFilename = JIT_SPEW_DIR "/ion.json";
153 const char* usePid = getenv("ION_SPEW_BY_PID");
154 if (usePid && *usePid != 0) {
155 uint32_t pid = getpid();
156 size_t len;
157 len = SprintfLiteral(jsonBuffer, JIT_SPEW_DIR "/ion%" PRIu32 ".json", pid);
158 if (bufferLength <= len) {
159 fprintf(stderr, "Warning: IonSpewer::init: Cannot serialize file name.");
160 return false;
162 jsonFilename = jsonBuffer;
165 if (!jsonOutput_.init(jsonFilename)) {
166 release();
167 return false;
170 jsonOutput_.printf("{\n \"functions\": [\n");
171 firstFunction_ = true;
173 inited_ = true;
174 return true;
177 void IonSpewer::beginFunction() {
178 // If we are doing a synchronous logging then we spew everything as we go,
179 // as this is useful in case of failure during the compilation. On the other
180 // hand, it is recommended to disable off thread compilation.
181 if (!getAsyncLogging() && !firstFunction_) {
182 LockGuard<Mutex> guard(outputLock_);
183 jsonOutput_.put(","); // separate functions
187 void IonSpewer::spewPass(GraphSpewer* gs) {
188 if (!getAsyncLogging()) {
189 LockGuard<Mutex> guard(outputLock_);
190 gs->dump(jsonOutput_);
194 void IonSpewer::endFunction(GraphSpewer* gs) {
195 LockGuard<Mutex> guard(outputLock_);
196 if (getAsyncLogging() && !firstFunction_) {
197 jsonOutput_.put(","); // separate functions
200 gs->dump(jsonOutput_);
201 firstFunction_ = false;
204 IonSpewer::~IonSpewer() {
205 if (!inited_) {
206 return;
209 jsonOutput_.printf("\n]}\n");
210 release();
213 GraphSpewer::GraphSpewer(TempAllocator* alloc)
214 : graph_(nullptr),
215 jsonPrinter_(alloc->lifoAlloc()),
216 jsonSpewer_(jsonPrinter_) {}
218 void GraphSpewer::init(MIRGraph* graph, JSScript* function) {
219 MOZ_ASSERT(!isSpewing());
220 if (!ionspewer.isEnabled()) {
221 return;
224 if (!FilterContainsLocation(function)) {
225 // filter out logs during the compilation.
226 filteredOutCompilations++;
227 MOZ_ASSERT(!isSpewing());
228 return;
231 graph_ = graph;
232 MOZ_ASSERT(isSpewing());
235 void GraphSpewer::beginFunction(JSScript* function) {
236 if (!isSpewing()) {
237 return;
239 jsonSpewer_.beginFunction(function);
240 ionspewer.beginFunction();
243 void GraphSpewer::beginWasmFunction(unsigned funcIndex) {
244 if (!isSpewing()) {
245 return;
247 jsonSpewer_.beginWasmFunction(funcIndex);
248 ionspewer.beginFunction();
251 void GraphSpewer::spewPass(const char* pass) {
252 if (!isSpewing()) {
253 return;
256 jsonSpewer_.beginPass(pass);
257 jsonSpewer_.spewMIR(graph_);
258 jsonSpewer_.spewLIR(graph_);
259 jsonSpewer_.endPass();
261 ionspewer.spewPass(this);
263 // As this function is used for debugging, we ignore any of the previous
264 // failures and ensure there is enough ballast space, such that we do not
265 // exhaust the ballast space before running the next phase.
266 AutoEnterOOMUnsafeRegion oomUnsafe;
267 if (!graph_->alloc().ensureBallast()) {
268 oomUnsafe.crash(
269 "Could not ensure enough ballast space after spewing graph "
270 "information.");
274 void GraphSpewer::spewPass(const char* pass, BacktrackingAllocator* ra) {
275 if (!isSpewing()) {
276 return;
279 jsonSpewer_.beginPass(pass);
280 jsonSpewer_.spewMIR(graph_);
281 jsonSpewer_.spewLIR(graph_);
282 jsonSpewer_.spewRanges(ra);
283 jsonSpewer_.endPass();
285 ionspewer.spewPass(this);
288 void GraphSpewer::endFunction() {
289 if (!ionspewer.isEnabled()) {
290 return;
293 if (!isSpewing()) {
294 MOZ_ASSERT(filteredOutCompilations != 0);
295 filteredOutCompilations--;
296 return;
299 jsonSpewer_.endFunction();
301 ionspewer.endFunction(this);
302 graph_ = nullptr;
305 void GraphSpewer::dump(Fprinter& jsonOut) {
306 if (!jsonPrinter_.hadOutOfMemory()) {
307 jsonPrinter_.exportInto(jsonOut);
308 } else {
309 jsonOut.put("{}");
311 jsonOut.flush();
312 jsonPrinter_.clear();
315 void jit::SpewBeginFunction(MIRGenerator* mir, JSScript* function) {
316 MIRGraph* graph = &mir->graph();
317 mir->graphSpewer().init(graph, function);
318 mir->graphSpewer().beginFunction(function);
321 void jit::SpewBeginWasmFunction(MIRGenerator* mir, unsigned funcIndex) {
322 MIRGraph* graph = &mir->graph();
323 mir->graphSpewer().init(graph, nullptr);
324 mir->graphSpewer().beginWasmFunction(funcIndex);
327 AutoSpewEndFunction::~AutoSpewEndFunction() {
328 mir_->graphSpewer().endFunction();
331 Fprinter& jit::JitSpewPrinter() {
332 static Fprinter out;
333 return out;
336 static void PrintHelpAndExit(int status = 0) {
337 fflush(nullptr);
338 printf(
339 "\n"
340 "usage: IONFLAGS=option,option,option,... where options can be:\n"
341 "\n"
342 " aborts Compilation abort messages\n"
343 " scripts Compiled scripts\n"
344 " mir MIR information\n"
345 " prune Prune unused branches\n"
346 " escape Escape analysis\n"
347 " alias Alias analysis\n"
348 " alias-sum Alias analysis: shows summaries for every block\n"
349 " gvn Global Value Numbering\n"
350 " licm Loop invariant code motion\n"
351 " flac Fold linear arithmetic constants\n"
352 " eaa Effective address analysis\n"
353 " sink Sink transformation\n"
354 " regalloc Register allocation\n"
355 " inline Inlining\n"
356 " snapshots Snapshot information\n"
357 " codegen Native code generation\n"
358 " bailouts Bailouts\n"
359 " caches Inline caches\n"
360 " osi Invalidation\n"
361 " safepoints Safepoints\n"
362 " pools Literal Pools (ARM only for now)\n"
363 " cacheflush Instruction Cache flushes (ARM only for now)\n"
364 " range Range Analysis\n"
365 " branch-hint Wasm Branch Hinting\n"
366 " wasmbce Wasm Bounds Check Elimination\n"
367 " shapeguards Redundant shape guard elimination\n"
368 " gcbarriers Redundant GC barrier elimination\n"
369 " loadkeys Loads used as property keys\n"
370 " stubfolding CacheIR stub folding\n"
371 " logs JSON visualization logging\n"
372 " logs-sync Same as logs, but flushes between each pass (sync. "
373 "compiled functions only).\n"
374 " profiling Profiling-related information\n"
375 " dump-mir-expr Dump the MIR expressions\n"
376 " warp-snapshots WarpSnapshots created by WarpOracle\n"
377 " warp-transpiler Warp CacheIR transpiler\n"
378 " warp-trial-inlining Trial inlining for Warp\n"
379 " all Everything\n"
380 "\n"
381 " bl-aborts Baseline compiler abort messages\n"
382 " bl-scripts Baseline script-compilation\n"
383 " bl-op Baseline compiler detailed op-specific messages\n"
384 " bl-ic Baseline inline-cache messages\n"
385 " bl-ic-fb Baseline IC fallback stub messages\n"
386 " bl-osr Baseline IC OSR messages\n"
387 " bl-bails Baseline bailouts\n"
388 " bl-dbg-osr Baseline debug mode on stack recompile messages\n"
389 " bl-all All baseline spew\n"
390 "\n"
391 "See also SPEW=help for information on the Structured Spewer."
392 "\n");
393 exit(status);
396 static bool IsFlag(const char* found, const char* flag) {
397 return strlen(found) == strlen(flag) && strcmp(found, flag) == 0;
400 void jit::CheckLogging() {
401 if (LoggingChecked) {
402 return;
405 LoggingChecked = true;
407 char* env = getenv("IONFLAGS");
408 if (!env) {
409 return;
412 const char* found = strtok(env, ",");
413 while (found) {
414 fprintf(stderr, "found tag: %s\n", found);
415 // We're at the end of a flag; check if the previous substring was a
416 // known flag (i-1 is the last character of the flag we just read).
417 if (IsFlag(found, "help")) {
418 PrintHelpAndExit();
419 } else if (IsFlag(found, "aborts")) {
420 EnableChannel(JitSpew_IonAbort);
421 } else if (IsFlag(found, "prune")) {
422 EnableChannel(JitSpew_Prune);
423 } else if (IsFlag(found, "escape")) {
424 EnableChannel(JitSpew_Escape);
425 } else if (IsFlag(found, "alias")) {
426 EnableChannel(JitSpew_Alias);
427 } else if (IsFlag(found, "alias-sum")) {
428 EnableChannel(JitSpew_AliasSummaries);
429 } else if (IsFlag(found, "scripts")) {
430 EnableChannel(JitSpew_IonScripts);
431 } else if (IsFlag(found, "mir")) {
432 EnableChannel(JitSpew_IonMIR);
433 } else if (IsFlag(found, "gvn")) {
434 EnableChannel(JitSpew_GVN);
435 } else if (IsFlag(found, "range")) {
436 EnableChannel(JitSpew_Range);
437 } else if (IsFlag(found, "wasmbce")) {
438 EnableChannel(JitSpew_WasmBCE);
439 } else if (IsFlag(found, "branch-hint")) {
440 EnableChannel(JitSpew_BranchHint);
441 } else if (IsFlag(found, "licm")) {
442 EnableChannel(JitSpew_LICM);
443 } else if (IsFlag(found, "flac")) {
444 EnableChannel(JitSpew_FLAC);
445 } else if (IsFlag(found, "eaa")) {
446 EnableChannel(JitSpew_EAA);
447 } else if (IsFlag(found, "sink")) {
448 EnableChannel(JitSpew_Sink);
449 } else if (IsFlag(found, "regalloc")) {
450 EnableChannel(JitSpew_RegAlloc);
451 } else if (IsFlag(found, "inline")) {
452 EnableChannel(JitSpew_Inlining);
453 } else if (IsFlag(found, "snapshots")) {
454 EnableChannel(JitSpew_IonSnapshots);
455 } else if (IsFlag(found, "codegen")) {
456 EnableChannel(JitSpew_Codegen);
457 } else if (IsFlag(found, "bailouts")) {
458 EnableChannel(JitSpew_IonBailouts);
459 } else if (IsFlag(found, "osi")) {
460 EnableChannel(JitSpew_IonInvalidate);
461 } else if (IsFlag(found, "caches")) {
462 EnableChannel(JitSpew_IonIC);
463 } else if (IsFlag(found, "safepoints")) {
464 EnableChannel(JitSpew_Safepoints);
465 } else if (IsFlag(found, "pools")) {
466 EnableChannel(JitSpew_Pools);
467 } else if (IsFlag(found, "cacheflush")) {
468 EnableChannel(JitSpew_CacheFlush);
469 } else if (IsFlag(found, "shapeguards")) {
470 EnableChannel(JitSpew_RedundantShapeGuards);
471 } else if (IsFlag(found, "gcbarriers")) {
472 EnableChannel(JitSpew_RedundantGCBarriers);
473 } else if (IsFlag(found, "loadkeys")) {
474 EnableChannel(JitSpew_MarkLoadsUsedAsPropertyKeys);
475 } else if (IsFlag(found, "stubfolding")) {
476 EnableChannel(JitSpew_StubFolding);
477 } else if (IsFlag(found, "logs")) {
478 EnableIonDebugAsyncLogging();
479 } else if (IsFlag(found, "logs-sync")) {
480 EnableIonDebugSyncLogging();
481 } else if (IsFlag(found, "profiling")) {
482 EnableChannel(JitSpew_Profiling);
483 } else if (IsFlag(found, "dump-mir-expr")) {
484 EnableChannel(JitSpew_MIRExpressions);
485 } else if (IsFlag(found, "warp-snapshots")) {
486 EnableChannel(JitSpew_WarpSnapshots);
487 } else if (IsFlag(found, "warp-transpiler")) {
488 EnableChannel(JitSpew_WarpTranspiler);
489 } else if (IsFlag(found, "warp-trial-inlining")) {
490 EnableChannel(JitSpew_WarpTrialInlining);
491 } else if (IsFlag(found, "all")) {
492 LoggingBits = uint64_t(-1);
493 } else if (IsFlag(found, "bl-aborts")) {
494 EnableChannel(JitSpew_BaselineAbort);
495 } else if (IsFlag(found, "bl-scripts")) {
496 EnableChannel(JitSpew_BaselineScripts);
497 } else if (IsFlag(found, "bl-op")) {
498 EnableChannel(JitSpew_BaselineOp);
499 } else if (IsFlag(found, "bl-ic")) {
500 EnableChannel(JitSpew_BaselineIC);
501 } else if (IsFlag(found, "bl-ic-fb")) {
502 EnableChannel(JitSpew_BaselineICFallback);
503 } else if (IsFlag(found, "bl-osr")) {
504 EnableChannel(JitSpew_BaselineOSR);
505 } else if (IsFlag(found, "bl-bails")) {
506 EnableChannel(JitSpew_BaselineBailouts);
507 } else if (IsFlag(found, "bl-dbg-osr")) {
508 EnableChannel(JitSpew_BaselineDebugModeOSR);
509 } else if (IsFlag(found, "bl-all")) {
510 EnableChannel(JitSpew_BaselineAbort);
511 EnableChannel(JitSpew_BaselineScripts);
512 EnableChannel(JitSpew_BaselineOp);
513 EnableChannel(JitSpew_BaselineIC);
514 EnableChannel(JitSpew_BaselineICFallback);
515 EnableChannel(JitSpew_BaselineOSR);
516 EnableChannel(JitSpew_BaselineBailouts);
517 EnableChannel(JitSpew_BaselineDebugModeOSR);
518 } else {
519 fprintf(stderr, "Unknown flag.\n");
520 PrintHelpAndExit(64);
522 found = strtok(nullptr, ",");
525 FILE* spewfh = stderr;
526 const char* filename = getenv("ION_SPEW_FILENAME");
527 if (filename && *filename) {
528 char actual_filename[2048] = {0};
529 SprintfLiteral(actual_filename, "%s.%d", filename, getpid());
530 spewfh = fopen(actual_filename, "w");
531 MOZ_RELEASE_ASSERT(spewfh);
532 setbuf(spewfh, nullptr); // Make unbuffered
534 JitSpewPrinter().init(spewfh);
537 JitSpewIndent::JitSpewIndent(JitSpewChannel channel) : channel_(channel) {
538 ChannelIndentLevel[channel]++;
541 JitSpewIndent::~JitSpewIndent() { ChannelIndentLevel[channel_]--; }
543 void jit::JitSpewStartVA(JitSpewChannel channel, const char* fmt, va_list ap) {
544 if (!JitSpewEnabled(channel)) {
545 return;
548 JitSpewHeader(channel);
549 Fprinter& out = JitSpewPrinter();
550 out.vprintf(fmt, ap);
553 void jit::JitSpewContVA(JitSpewChannel channel, const char* fmt, va_list ap) {
554 if (!JitSpewEnabled(channel)) {
555 return;
558 Fprinter& out = JitSpewPrinter();
559 out.vprintf(fmt, ap);
562 void jit::JitSpewFin(JitSpewChannel channel) {
563 if (!JitSpewEnabled(channel)) {
564 return;
567 Fprinter& out = JitSpewPrinter();
568 out.put("\n");
571 void jit::JitSpewVA(JitSpewChannel channel, const char* fmt, va_list ap) {
572 JitSpewStartVA(channel, fmt, ap);
573 JitSpewFin(channel);
576 void jit::JitSpew(JitSpewChannel channel, const char* fmt, ...) {
577 va_list ap;
578 va_start(ap, fmt);
579 JitSpewVA(channel, fmt, ap);
581 // Suppress hazard analysis on logPrintVA function pointer.
582 JS::AutoSuppressGCAnalysis suppress;
584 switch (channel) {
585 # define SpewChannel(x) \
586 case JitSpew_##x: \
587 if (x##Module.shouldLog(mozilla::LogLevel::Debug)) { \
588 x##Module.interface.logPrintVA(x##Module.logger, \
589 mozilla::LogLevel::Debug, fmt, ap); \
591 break;
593 JITSPEW_CHANNEL_LIST(SpewChannel)
595 # undef SpewChannel
596 case JitSpew_Terminator:
597 MOZ_CRASH("Unexpected JitSpew");
600 va_end(ap);
603 void jit::JitSpewDef(JitSpewChannel channel, const char* str,
604 MDefinition* def) {
605 if (!JitSpewEnabled(channel)) {
606 return;
609 JitSpewHeader(channel);
610 Fprinter& out = JitSpewPrinter();
611 out.put(str);
612 def->dump(out);
613 def->dumpLocation(out);
616 void jit::JitSpewStart(JitSpewChannel channel, const char* fmt, ...) {
617 va_list ap;
618 va_start(ap, fmt);
619 JitSpewStartVA(channel, fmt, ap);
620 va_end(ap);
622 void jit::JitSpewCont(JitSpewChannel channel, const char* fmt, ...) {
623 va_list ap;
624 va_start(ap, fmt);
625 JitSpewContVA(channel, fmt, ap);
626 va_end(ap);
629 void jit::JitSpewHeader(JitSpewChannel channel) {
630 if (!JitSpewEnabled(channel)) {
631 return;
634 Fprinter& out = JitSpewPrinter();
635 out.printf("[%s] ", ChannelNames[channel]);
636 for (size_t i = ChannelIndentLevel[channel]; i != 0; i--) {
637 out.put(" ");
641 void jit::EnableChannel(JitSpewChannel channel) {
642 MOZ_ASSERT(LoggingChecked);
643 LoggingBits |= uint64_t(1) << uint32_t(channel);
646 void jit::DisableChannel(JitSpewChannel channel) {
647 MOZ_ASSERT(LoggingChecked);
648 LoggingBits &= ~(uint64_t(1) << uint32_t(channel));
651 const char* js::jit::ValTypeToString(JSValueType type) {
652 switch (type) {
653 case JSVAL_TYPE_DOUBLE:
654 return "Double";
655 case JSVAL_TYPE_INT32:
656 return "Int32";
657 case JSVAL_TYPE_BOOLEAN:
658 return "Boolean";
659 case JSVAL_TYPE_UNDEFINED:
660 return "Undefined";
661 case JSVAL_TYPE_NULL:
662 return "Null";
663 case JSVAL_TYPE_MAGIC:
664 return "Magic";
665 case JSVAL_TYPE_STRING:
666 return "String";
667 case JSVAL_TYPE_SYMBOL:
668 return "Symbol";
669 case JSVAL_TYPE_PRIVATE_GCTHING:
670 return "PrivateGCThing";
671 case JSVAL_TYPE_BIGINT:
672 return "BigInt";
673 case JSVAL_TYPE_OBJECT:
674 return "Object";
675 case JSVAL_TYPE_UNKNOWN:
676 return "None";
677 default:
678 MOZ_CRASH("Unknown JSValueType");
682 #endif /* JS_JITSPEW */