Bug 1328228: IonMonkey - Split IONFLAGS=trackopts to IONFLAGS=trackopts-ext, r=shu
authorHannes Verschore <hv1989@gmail.com>
Mon, 09 Jan 2017 15:05:37 +0100
changeset 328525 1e155739b693921263efab6738e4ae3457d61d4c
parent 328524 c0593a4dc2012821d9799e3abfed3469f7fe41d1
child 328526 b4bc05f80383f464349cdba8f9ca34236767b333
push id85462
push userhv1989@gmail.com
push dateMon, 09 Jan 2017 14:07:57 +0000
treeherdermozilla-inbound@953bb49f3aaf [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersshu
bugs1328228
milestone53.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1328228: IonMonkey - Split IONFLAGS=trackopts to IONFLAGS=trackopts-ext, r=shu
js/src/jit/CodeGenerator.cpp
js/src/jit/JitSpewer.cpp
js/src/jit/JitSpewer.h
js/src/jit/OptimizationTracking.cpp
js/src/jit/OptimizationTracking.h
js/src/jit/shared/CodeGenerator-shared.cpp
--- a/js/src/jit/CodeGenerator.cpp
+++ b/js/src/jit/CodeGenerator.cpp
@@ -5180,16 +5180,40 @@ CodeGenerator::emitDebugForceBailing(LIn
         }
         masm.bind(&notBail);
         masm.pop(temp);
     }
     masm.bind(&done);
 }
 #endif
 
+static void
+DumpTrackedSite(const BytecodeSite* site)
+{
+    if (!JitSpewEnabled(JitSpew_OptimizationTracking))
+        return;
+
+    unsigned column = 0;
+    unsigned lineNumber = PCToLineNumber(site->script(), site->pc(), &column);
+    JitSpew(JitSpew_OptimizationTracking, "Types for %s at %s:%u:%u",
+            CodeName[JSOp(*site->pc())],
+            site->script()->filename(),
+            lineNumber,
+            column);
+}
+
+static void
+DumpTrackedOptimizations(TrackedOptimizations* optimizations)
+{
+    if (!JitSpewEnabled(JitSpew_OptimizationTracking))
+        return;
+
+    optimizations->spew(JitSpew_OptimizationTracking);
+}
+
 bool
 CodeGenerator::generateBody()
 {
     IonScriptCounts* counts = maybeCreateScriptCounts();
 
 #if defined(JS_ION_PERF)
     PerfSpewer* perfSpewer = &perfSpewer_;
     if (gen->compilingWasm())
@@ -5228,16 +5252,17 @@ CodeGenerator::generateBody()
         masm.bind(current->label());
 
         mozilla::Maybe<ScriptCountBlockState> blockCounts;
         if (counts) {
             blockCounts.emplace(&counts->block(i), &masm);
             if (!blockCounts->init())
                 return false;
         }
+        TrackedOptimizations* last = nullptr;
 
 #if defined(JS_ION_PERF)
         perfSpewer->startBasicBlock(current->mir(), masm);
 #endif
 
         for (LInstructionIterator iter = current->begin(); iter != current->end(); iter++) {
             if (!alloc().ensureBallast())
                 return false;
@@ -5261,16 +5286,21 @@ CodeGenerator::generateBody()
                 // Only add instructions that have a tracked inline script tree.
                 if (iter->mirRaw()->trackedTree()) {
                     if (!addNativeToBytecodeEntry(iter->mirRaw()->trackedSite()))
                         return false;
                 }
 
                 // Track the start native offset of optimizations.
                 if (iter->mirRaw()->trackedOptimizations()) {
+                    if (last != iter->mirRaw()->trackedOptimizations()) {
+                        DumpTrackedSite(iter->mirRaw()->trackedSite());
+                        DumpTrackedOptimizations(iter->mirRaw()->trackedOptimizations());
+                        last = iter->mirRaw()->trackedOptimizations();
+                    }
                     if (!addTrackedOptimizationsEntry(iter->mirRaw()->trackedOptimizations()))
                         return false;
                 }
             }
 
 #ifdef DEBUG
             setElement(*iter); // needed to encode correct snapshot location.
             emitDebugForceBailing(*iter);
--- a/js/src/jit/JitSpewer.cpp
+++ b/js/src/jit/JitSpewer.cpp
@@ -436,16 +436,17 @@ jit::CheckLogging()
             "  cacheflush    Instruction Cache flushes (ARM only for now)\n"
             "  range         Range Analysis\n"
             "  unroll        Loop unrolling\n"
             "  logs          C1 and JSON visualization logging\n"
             "  logs-sync     Same as logs, but flushes between each pass (sync. compiled functions only).\n"
             "  profiling     Profiling-related information\n"
             "  trackopts     Optimization tracking information gathered by SPS. "
                             "(Note: call enableSPSProfiling() in your script to enable it).\n"
+            "  trackopts-ext Encoding information about optimization tracking"
             "  dump-mir-expr Dump the MIR expressions\n"
             "  cfg           Control flow graph generation\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"
@@ -512,16 +513,18 @@ jit::CheckLogging()
     if (ContainsFlag(env, "logs"))
         EnableIonDebugAsyncLogging();
     if (ContainsFlag(env, "logs-sync"))
         EnableIonDebugSyncLogging();
     if (ContainsFlag(env, "profiling"))
         EnableChannel(JitSpew_Profiling);
     if (ContainsFlag(env, "trackopts"))
         EnableChannel(JitSpew_OptimizationTracking);
+    if (ContainsFlag(env, "trackopts-ext"))
+        EnableChannel(JitSpew_OptimizationTrackingExtended);
     if (ContainsFlag(env, "dump-mir-expr"))
         EnableChannel(JitSpew_MIRExpressions);
     if (ContainsFlag(env, "cfg"))
         EnableChannel(JitSpew_CFG);
     if (ContainsFlag(env, "all"))
         LoggingBits = uint64_t(-1);
 
     if (ContainsFlag(env, "bl-aborts"))
--- a/js/src/jit/JitSpewer.h
+++ b/js/src/jit/JitSpewer.h
@@ -57,16 +57,17 @@ namespace jit {
     /* Debug info about safepoints */       \
     _(Safepoints)                           \
     /* Debug info about Pools*/             \
     _(Pools)                                \
     /* Profiling-related information */     \
     _(Profiling)                            \
     /* Information of tracked opt strats */ \
     _(OptimizationTracking)                 \
+    _(OptimizationTrackingExtended)         \
     /* Debug info about the I$ */           \
     _(CacheFlush)                           \
     /* Output a list of MIR expressions */  \
     _(MIRExpressions)                       \
     /* Print control flow graph */          \
     _(CFG)                                  \
                                             \
     /* BASELINE COMPILER SPEW */            \
--- a/js/src/jit/OptimizationTracking.cpp
+++ b/js/src/jit/OptimizationTracking.cpp
@@ -131,49 +131,51 @@ JS::TrackedTypeSiteString(TrackedTypeSit
 #undef TYPESITE_CASE
 
       default:
         MOZ_CRASH("bad type site");
     }
 }
 
 void
-SpewTempOptimizationTypeInfoVector(const TempOptimizationTypeInfoVector* types,
+SpewTempOptimizationTypeInfoVector(JitSpewChannel channel,
+                                   const TempOptimizationTypeInfoVector* types,
                                    const char* indent = nullptr)
 {
 #ifdef JS_JITSPEW
     for (const OptimizationTypeInfo* t = types->begin(); t != types->end(); t++) {
-        JitSpewStart(JitSpew_OptimizationTracking, "   %s%s of type %s, type set",
+        JitSpewStart(channel, "   %s%s of type %s, type set",
                      indent ? indent : "",
                      TrackedTypeSiteString(t->site()), StringFromMIRType(t->mirType()));
         for (uint32_t i = 0; i < t->types().length(); i++)
-            JitSpewCont(JitSpew_OptimizationTracking, " %s", TypeSet::TypeString(t->types()[i]));
-        JitSpewFin(JitSpew_OptimizationTracking);
+            JitSpewCont(channel, " %s", TypeSet::TypeString(t->types()[i]));
+        JitSpewFin(channel);
     }
 #endif
 }
 
 void
-SpewTempOptimizationAttemptsVector(const TempOptimizationAttemptsVector* attempts,
+SpewTempOptimizationAttemptsVector(JitSpewChannel channel,
+                                   const TempOptimizationAttemptsVector* attempts,
                                    const char* indent = nullptr)
 {
 #ifdef JS_JITSPEW
     for (const OptimizationAttempt* a = attempts->begin(); a != attempts->end(); a++) {
-        JitSpew(JitSpew_OptimizationTracking, "   %s%s: %s", indent ? indent : "",
+        JitSpew(channel, "   %s%s: %s", indent ? indent : "",
                 TrackedStrategyString(a->strategy()), TrackedOutcomeString(a->outcome()));
     }
 #endif
 }
 
 void
-TrackedOptimizations::spew() const
+TrackedOptimizations::spew(JitSpewChannel channel) const
 {
 #ifdef JS_JITSPEW
-    SpewTempOptimizationTypeInfoVector(&types_);
-    SpewTempOptimizationAttemptsVector(&attempts_);
+    SpewTempOptimizationTypeInfoVector(channel, &types_);
+    SpewTempOptimizationAttemptsVector(channel, &attempts_);
 #endif
 }
 
 bool
 OptimizationTypeInfo::trackTypeSet(TemporaryTypeSet* typeSet)
 {
     if (!typeSet)
         return true;
@@ -287,17 +289,17 @@ struct FrequencyComparator
     }
 };
 
 bool
 UniqueTrackedOptimizations::sortByFrequency(JSContext* cx)
 {
     MOZ_ASSERT(!sorted());
 
-    JitSpew(JitSpew_OptimizationTracking, "=> Sorting unique optimizations by frequency");
+    JitSpew(JitSpew_OptimizationTrackingExtended, "=> Sorting unique optimizations by frequency");
 
     // Sort by frequency.
     Vector<SortEntry> entries(cx);
     for (AttemptsMap::Range r = map_.all(); !r.empty(); r.popFront()) {
         SortEntry entry;
         entry.types = r.front().key().types;
         entry.attempts = r.front().key().attempts;
         entry.frequency = r.front().value().frequency;
@@ -321,17 +323,17 @@ UniqueTrackedOptimizations::sortByFreque
     for (size_t i = 0; i < entries.length(); i++) {
         Key key;
         key.types = entries[i].types;
         key.attempts = entries[i].attempts;
         AttemptsMap::Ptr p = map_.lookup(key);
         MOZ_ASSERT(p);
         p->value().index = sorted_.length();
 
-        JitSpew(JitSpew_OptimizationTracking, "   Entry %" PRIuSIZE " has frequency %" PRIu32,
+        JitSpew(JitSpew_OptimizationTrackingExtended, "   Entry %" PRIuSIZE " has frequency %" PRIu32,
                 sorted_.length(), p->value().frequency);
 
         if (!sorted_.append(entries[i]))
             return false;
     }
 
     return true;
 }
@@ -760,40 +762,40 @@ IonTrackedOptimizationsRegion::WriteDelt
 
 /* static */ bool
 IonTrackedOptimizationsRegion::WriteRun(CompactBufferWriter& writer,
                                         const NativeToTrackedOptimizations* start,
                                         const NativeToTrackedOptimizations* end,
                                         const UniqueTrackedOptimizations& unique)
 {
     // Write the header, which is the range that this whole run encompasses.
-    JitSpew(JitSpew_OptimizationTracking, "     Header: [%" PRIuSIZE ", %" PRIuSIZE "]",
+    JitSpew(JitSpew_OptimizationTrackingExtended, "     Header: [%" PRIuSIZE ", %" PRIuSIZE "]",
             start->startOffset.offset(), (end - 1)->endOffset.offset());
     writer.writeUnsigned(start->startOffset.offset());
     writer.writeUnsigned((end - 1)->endOffset.offset());
 
     // Write the first entry of the run, which is not delta-encoded.
-    JitSpew(JitSpew_OptimizationTracking,
+    JitSpew(JitSpew_OptimizationTrackingExtended,
             "     [%6" PRIuSIZE ", %6" PRIuSIZE "]                        vector %3u, offset %4" PRIuSIZE,
             start->startOffset.offset(), start->endOffset.offset(),
             unique.indexOf(start->optimizations), writer.length());
     uint32_t prevEndOffset = start->endOffset.offset();
     writer.writeUnsigned(prevEndOffset);
     writer.writeByte(unique.indexOf(start->optimizations));
 
     // Delta encode the run.
     for (const NativeToTrackedOptimizations* entry = start + 1; entry != end; entry++) {
         uint32_t startOffset = entry->startOffset.offset();
         uint32_t endOffset = entry->endOffset.offset();
 
         uint32_t startDelta = startOffset - prevEndOffset;
         uint32_t length = endOffset - startOffset;
         uint8_t index = unique.indexOf(entry->optimizations);
 
-        JitSpew(JitSpew_OptimizationTracking,
+        JitSpew(JitSpew_OptimizationTrackingExtended,
                 "     [%6u, %6u] delta [+%5u, +%5u] vector %3u, offset %4" PRIuSIZE,
                 startOffset, endOffset, startDelta, length, index, writer.length());
 
         WriteDelta(writer, startDelta, length, index);
 
         prevEndOffset = endOffset;
     }
 
@@ -806,31 +808,31 @@ IonTrackedOptimizationsRegion::WriteRun(
 static bool
 WriteOffsetsTable(CompactBufferWriter& writer, const Vector<uint32_t, 16>& offsets,
                   uint32_t* tableOffsetp)
 {
     // 4-byte align for the uint32s.
     uint32_t padding = sizeof(uint32_t) - (writer.length() % sizeof(uint32_t));
     if (padding == sizeof(uint32_t))
         padding = 0;
-    JitSpew(JitSpew_OptimizationTracking, "   Padding %u byte%s",
+    JitSpew(JitSpew_OptimizationTrackingExtended, "   Padding %u byte%s",
             padding, padding == 1 ? "" : "s");
     for (uint32_t i = 0; i < padding; i++)
         writer.writeByte(0);
 
     // Record the start of the table to compute reverse offsets for entries.
     uint32_t tableOffset = writer.length();
 
     // Write how many bytes were padded and numEntries.
     writer.writeNativeEndianUint32_t(padding);
     writer.writeNativeEndianUint32_t(offsets.length());
 
     // Write entry offset table.
     for (size_t i = 0; i < offsets.length(); i++) {
-        JitSpew(JitSpew_OptimizationTracking, "   Entry %" PRIuSIZE " reverse offset %u",
+        JitSpew(JitSpew_OptimizationTrackingExtended, "   Entry %" PRIuSIZE " reverse offset %u",
                 i, tableOffset - padding - offsets[i]);
         writer.writeNativeEndianUint32_t(tableOffset - padding - offsets[i]);
     }
 
     if (writer.oom())
         return false;
 
     *tableOffsetp = tableOffset;
@@ -865,41 +867,44 @@ InterpretedFunctionFilenameAndLineNumber
     }
 }
 
 static void
 SpewConstructor(TypeSet::Type ty, JSFunction* constructor)
 {
 #ifdef JS_JITSPEW
     if (!constructor->isInterpreted()) {
-        JitSpew(JitSpew_OptimizationTracking, "   Unique type %s has native constructor",
+        JitSpew(JitSpew_OptimizationTrackingExtended, "   Unique type %s has native constructor",
                 TypeSet::TypeString(ty));
         return;
     }
 
     char buf[512];
     if (constructor->displayAtom())
         PutEscapedString(buf, 512, constructor->displayAtom(), 0);
     else
         snprintf(buf, mozilla::ArrayLength(buf), "??");
 
     const char* filename;
     Maybe<unsigned> lineno;
     InterpretedFunctionFilenameAndLineNumber(constructor, &filename, &lineno);
 
-    JitSpew(JitSpew_OptimizationTracking, "   Unique type %s has constructor %s (%s:%u)",
+    JitSpew(JitSpew_OptimizationTrackingExtended, "   Unique type %s has constructor %s (%s:%u)",
             TypeSet::TypeString(ty), buf, filename, lineno.isSome() ? *lineno : 0);
 #endif
 }
 
 static void
 SpewAllocationSite(TypeSet::Type ty, JSScript* script, uint32_t offset)
 {
 #ifdef JS_JITSPEW
-    JitSpew(JitSpew_OptimizationTracking, "   Unique type %s has alloc site %s:%u",
+    if (!JitSpewEnabled(JitSpew_OptimizationTrackingExtended))
+        return;
+
+    JitSpew(JitSpew_OptimizationTrackingExtended, "   Unique type %s has alloc site %s:%u",
             TypeSet::TypeString(ty), script->filename(),
             PCToLineNumber(script, script->offsetToPC(offset)));
 #endif
 }
 
 bool
 jit::WriteIonTrackedOptimizationsTable(JSContext* cx, CompactBufferWriter& writer,
                                        const NativeToTrackedOptimizations* start,
@@ -911,35 +916,35 @@ jit::WriteIonTrackedOptimizationsTable(J
                                        uint32_t* optimizationTableOffsetp,
                                        IonTrackedTypeVector* allTypes)
 {
     MOZ_ASSERT(unique.sorted());
 
 #ifdef JS_JITSPEW
     // Spew training data, which may be fed into a script to determine a good
     // encoding strategy.
-    if (JitSpewEnabled(JitSpew_OptimizationTracking)) {
-        JitSpewStart(JitSpew_OptimizationTracking, "=> Training data: ");
+    if (JitSpewEnabled(JitSpew_OptimizationTrackingExtended)) {
+        JitSpewStart(JitSpew_OptimizationTrackingExtended, "=> Training data: ");
         for (const NativeToTrackedOptimizations* entry = start; entry != end; entry++) {
-            JitSpewCont(JitSpew_OptimizationTracking, "%" PRIuSIZE ",%" PRIuSIZE ",%u ",
+            JitSpewCont(JitSpew_OptimizationTrackingExtended, "%" PRIuSIZE ",%" PRIuSIZE ",%u ",
                         entry->startOffset.offset(), entry->endOffset.offset(),
                         unique.indexOf(entry->optimizations));
         }
-        JitSpewFin(JitSpew_OptimizationTracking);
+        JitSpewFin(JitSpew_OptimizationTrackingExtended);
     }
 #endif
 
     Vector<uint32_t, 16> offsets(cx);
     const NativeToTrackedOptimizations* entry = start;
 
     // Write out region offloads, partitioned into runs.
     JitSpew(JitSpew_Profiling, "=> Writing regions");
     while (entry != end) {
         uint32_t runLength = IonTrackedOptimizationsRegion::ExpectedRunLength(entry, end);
-        JitSpew(JitSpew_OptimizationTracking,
+        JitSpew(JitSpew_OptimizationTrackingExtended,
                 "   Run at entry %" PRIuSIZE ", length %" PRIu32 ", offset %" PRIuSIZE,
                 size_t(entry - start), runLength, writer.length());
 
         if (!offsets.append(writer.length()))
             return false;
 
         if (!IonTrackedOptimizationsRegion::WriteRun(writer, entry, entry + runLength, unique))
             return false;
@@ -953,30 +958,30 @@ jit::WriteIonTrackedOptimizationsTable(J
 
     *numRegions = offsets.length();
 
     // Clear offsets so that it may be reused below for the unique
     // optimizations table.
     offsets.clear();
 
     const UniqueTrackedOptimizations::SortedVector& vec = unique.sortedVector();
-    JitSpew(JitSpew_OptimizationTracking, "=> Writing unique optimizations table with %" PRIuSIZE " entr%s",
+    JitSpew(JitSpew_OptimizationTrackingExtended, "=> Writing unique optimizations table with %" PRIuSIZE " entr%s",
             vec.length(), vec.length() == 1 ? "y" : "ies");
 
     // Write out type info payloads.
     UniqueTrackedTypes uniqueTypes(cx);
     if (!uniqueTypes.init())
         return false;
 
     for (const UniqueTrackedOptimizations::SortEntry* p = vec.begin(); p != vec.end(); p++) {
         const TempOptimizationTypeInfoVector* v = p->types;
-        JitSpew(JitSpew_OptimizationTracking,
+        JitSpew(JitSpew_OptimizationTrackingExtended,
                 "   Type info entry %" PRIuSIZE " of length %" PRIuSIZE ", offset %" PRIuSIZE,
                 size_t(p - vec.begin()), v->length(), writer.length());
-        SpewTempOptimizationTypeInfoVector(v, "  ");
+        SpewTempOptimizationTypeInfoVector(JitSpew_OptimizationTrackingExtended, v, "  ");
 
         if (!offsets.append(writer.length()))
             return false;
 
         for (const OptimizationTypeInfo* t = v->begin(); t != v->end(); t++) {
             if (!t->writeCompact(cx, writer, uniqueTypes))
                 return false;
         }
@@ -1014,20 +1019,22 @@ jit::WriteIonTrackedOptimizationsTable(J
 
     if (!WriteOffsetsTable(writer, offsets, typesTableOffsetp))
         return false;
     offsets.clear();
 
     // Write out attempts payloads.
     for (const UniqueTrackedOptimizations::SortEntry* p = vec.begin(); p != vec.end(); p++) {
         const TempOptimizationAttemptsVector* v = p->attempts;
-        JitSpew(JitSpew_OptimizationTracking,
-                "   Attempts entry %" PRIuSIZE " of length %" PRIuSIZE ", offset %" PRIuSIZE,
-                size_t(p - vec.begin()), v->length(), writer.length());
-        SpewTempOptimizationAttemptsVector(v, "  ");
+        if (JitSpewEnabled(JitSpew_OptimizationTrackingExtended)) {
+            JitSpew(JitSpew_OptimizationTrackingExtended,
+                    "   Attempts entry %" PRIuSIZE " of length %" PRIuSIZE ", offset %" PRIuSIZE,
+                    size_t(p - vec.begin()), v->length(), writer.length());
+            SpewTempOptimizationAttemptsVector(JitSpew_OptimizationTrackingExtended, v, "  ");
+        }
 
         if (!offsets.append(writer.length()))
             return false;
 
         for (const OptimizationAttempt* a = v->begin(); a != v->end(); a++)
             a->writeCompact(writer);
     }
 
--- a/js/src/jit/OptimizationTracking.h
+++ b/js/src/jit/OptimizationTracking.h
@@ -119,17 +119,17 @@ class TrackedOptimizations : public Temp
     MOZ_MUST_USE bool trackAttempt(JS::TrackedStrategy strategy);
     void amendAttempt(uint32_t index);
     void trackOutcome(JS::TrackedOutcome outcome);
     void trackSuccess();
 
     bool matchTypes(const TempOptimizationTypeInfoVector& other) const;
     bool matchAttempts(const TempOptimizationAttemptsVector& other) const;
 
-    void spew() const;
+    void spew(JitSpewChannel channel) const;
 };
 
 // Assigns each unique sequence of optimization attempts an index; outputs a
 // compact table.
 class UniqueTrackedOptimizations
 {
   public:
     struct SortEntry
--- a/js/src/jit/shared/CodeGenerator-shared.cpp
+++ b/js/src/jit/shared/CodeGenerator-shared.cpp
@@ -919,20 +919,20 @@ CodeGeneratorShared::generateCompactTrac
     trackedOptimizationsMap_ = data;
     trackedOptimizationsMapSize_ = writer.length();
     trackedOptimizationsRegionTableOffset_ = regionTableOffset;
     trackedOptimizationsTypesTableOffset_ = typesTableOffset;
     trackedOptimizationsAttemptsTableOffset_ = attemptsTableOffset;
 
     verifyCompactTrackedOptimizationsMap(code, numRegions, unique, allTypes);
 
-    JitSpew(JitSpew_OptimizationTracking,
+    JitSpew(JitSpew_OptimizationTrackingExtended,
             "== Compact Native To Optimizations Map [%p-%p] size %u",
             data, data + trackedOptimizationsMapSize_, trackedOptimizationsMapSize_);
-    JitSpew(JitSpew_OptimizationTracking,
+    JitSpew(JitSpew_OptimizationTrackingExtended,
             "     with type list of length %" PRIuSIZE ", size %" PRIuSIZE,
             allTypes->length(), allTypes->length() * sizeof(IonTrackedTypeWithAddendum));
 
     return true;
 }
 
 #ifdef DEBUG
 class ReadTempAttemptsVectorOp : public JS::ForEachTrackedOptimizationAttemptOp