Inliner: gather summary stats and dump to Jit CSV log

Collect per-method summary stats about inlining: number of calls,
number of candidates, etc.

Commit migrated from https://github.com/dotnet/coreclr/commit/da5693edb3223adb36aa4088ba7113d7cd065c22

diff --git a/src/coreclr/src/jit/compiler.cpp b/src/coreclr/src/jit/compiler.cpp
index 1f8a319..ad5cdb8 100644 (file)
--- a/src/coreclr/src/jit/compiler.cpp
+++ b/src/coreclr/src/jit/compiler.cpp
@@ -3984,6 +3984,12 @@ void                 Compiler::compCompile(void * * methodCodePtr,
                                            ULONG  * methodCodeSize,
                                            CORJIT_FLAGS * compileFlags)
 {
+    if (compIsForInlining())
+    {
+        // Notify root instance that an inline attempt is about to import IL
+        impInlineRoot()->m_inlineStrategy->NoteImport();
+    }
+
     hashBv::Init(this);
 
     VarSetOps::AssignAllowUninitRhs(this, compCurLife, VarSetOps::UninitVal());
@@ -7092,6 +7098,9 @@ void JitTimer::PrintCsvHeader()
         {
             fprintf(fp, "\"%s\",", PhaseNames[i]);
         }
+
+        InlineStrategy::DumpCsvHeader(fp);
+
         fprintf(fp, "\"Total Cycles\",");
         fprintf(fp, "\"CPS\"\n");
         fclose(fp);
@@ -7136,6 +7145,9 @@ void JitTimer::PrintCsvMethodStats(Compiler* comp)
             totCycles += m_info.m_cyclesByPhase[i];
         fprintf(fp, "%I64u,", m_info.m_cyclesByPhase[i]);
     }
+
+    comp->m_inlineStrategy->DumpCsvData(fp);
+
     fprintf(fp, "%I64u,", m_info.m_totalCycles);
     fprintf(fp, "%f\n", CycleTimer::CyclesPerSecond());
     fclose(fp);

diff --git a/src/coreclr/src/jit/flowgraph.cpp b/src/coreclr/src/jit/flowgraph.cpp
index baf3575..b6f9ce4 100644 (file)
--- a/src/coreclr/src/jit/flowgraph.cpp
+++ b/src/coreclr/src/jit/flowgraph.cpp
@@ -4872,6 +4872,7 @@ TOO_FAR:
                 
                 if (compInlineResult->IsFailure())
                 {
+                    impInlineRoot()->m_inlineStrategy->NoteUnprofitable();
                     JITDUMP("\n\nInline expansion aborted, inline not profitable\n");
                     return;
                 }

diff --git a/src/coreclr/src/jit/importer.cpp b/src/coreclr/src/jit/importer.cpp
index d2a92ee..eed46f5 100644 (file)
--- a/src/coreclr/src/jit/importer.cpp
+++ b/src/coreclr/src/jit/importer.cpp
@@ -16970,7 +16970,10 @@ void          Compiler::impMarkInlineCandidate(GenTreePtr callNode,
                                                CORINFO_CONTEXT_HANDLE exactContextHnd, 
                                                CORINFO_CALL_INFO* callInfo)
 {
-    if  (!opts.OptEnabled(CLFLG_INLINING))
+    // Let the strategy know there's another call
+    impInlineRoot()->m_inlineStrategy->NoteCall();
+
+    if (!opts.OptEnabled(CLFLG_INLINING))
     {                 
         /* XXX Mon 8/18/2008
          * This assert is misleading.  The caller does not ensure that we have CLFLG_INLINING set before

diff --git a/src/coreclr/src/jit/inline.cpp b/src/coreclr/src/jit/inline.cpp
index cca6757..f813427 100644 (file)
--- a/src/coreclr/src/jit/inline.cpp
+++ b/src/coreclr/src/jit/inline.cpp
@@ -734,8 +734,13 @@ InlineStrategy::InlineStrategy(Compiler* compiler)
     : m_Compiler(compiler)
     , m_RootContext(nullptr)
     , m_LastSuccessfulPolicy(nullptr)
+    , m_CallCount(0)
     , m_CandidateCount(0)
-    , m_InlineAttemptCount(0)
+    , m_AlwaysCandidateCount(0)
+    , m_ForceCandidateCount(0)
+    , m_DiscretionaryCandidateCount(0)
+    , m_UnprofitableCandidateCount(0)
+    , m_ImportCount(0)
     , m_InlineCount(0)
     , m_MaxInlineSize(DEFAULT_MAX_INLINE_SIZE)
     , m_MaxInlineDepth(DEFAULT_MAX_INLINE_DEPTH)
@@ -837,11 +842,86 @@ InlineContext* InlineStrategy::GetRootContext()
 }
 
 //------------------------------------------------------------------------
-// NoteCandidate: do bookkeeping for an inline candidate
+// NoteAttempt: do bookkeeping for an inline attempt
+//
+// Arguments:
+//    result -- InlineResult for successful inline candidate
+
+void InlineStrategy::NoteAttempt(InlineResult* result)
+{
+    assert(result->IsCandidate());
+    InlineObservation obs = result->GetObservation();
+
+    if (obs == InlineObservation::CALLEE_BELOW_ALWAYS_INLINE_SIZE)
+    {
+        m_AlwaysCandidateCount++;
+    }
+    else if (obs == InlineObservation::CALLEE_IS_FORCE_INLINE)
+    {
+        m_ForceCandidateCount++;
+    }
+    else
+    {
+        m_DiscretionaryCandidateCount++;
+    }
+}
+
+//------------------------------------------------------------------------
+// DumpCsvHeader: dump header for csv inline stats
+//
+// Argument:
+//     fp -- file for dump output
 
-void InlineStrategy::NoteCandidate()
+void InlineStrategy::DumpCsvHeader(FILE* fp)
 {
-    m_CandidateCount++;
+    fprintf(fp, "\"InlineCalls\",");
+    fprintf(fp, "\"InlineCandidates\",");
+    fprintf(fp, "\"InlineAlways\",");
+    fprintf(fp, "\"InlineForce\",");
+    fprintf(fp, "\"InlineDiscretionary\",");
+    fprintf(fp, "\"InlineUnprofitable\",");
+    fprintf(fp, "\"InlineEarlyFail\",");
+    fprintf(fp, "\"InlineImport\",");
+    fprintf(fp, "\"InlineLateFail\",");
+    fprintf(fp, "\"InlineSuccess\",");
+}
+
+//------------------------------------------------------------------------
+// DumpCsvData: dump data for csv inline stats
+//
+// Argument:
+//     fp -- file for dump output
+
+void InlineStrategy::DumpCsvData(FILE* fp)
+{
+    fprintf(fp, "%u,", m_CallCount);
+    fprintf(fp, "%u,", m_CandidateCount);
+    fprintf(fp, "%u,", m_AlwaysCandidateCount);
+    fprintf(fp, "%u,", m_ForceCandidateCount);
+    fprintf(fp, "%u,", m_DiscretionaryCandidateCount);
+    fprintf(fp, "%u,", m_UnprofitableCandidateCount);
+
+    // Early failures are cases where candates are rejected between
+    // the time the jit invokes the inlinee compiler and the time it
+    // starts to import the inlinee IL.
+    //
+    // So they are "cheaper" that late failures.
+
+    unsigned profitableCandidateCount =
+        m_DiscretionaryCandidateCount - m_UnprofitableCandidateCount;
+
+    unsigned earlyFailCount = m_CandidateCount
+        - m_AlwaysCandidateCount
+        - m_ForceCandidateCount
+        - profitableCandidateCount;
+
+    fprintf(fp, "%u,", earlyFailCount);
+
+    unsigned lateFailCount = m_ImportCount - m_InlineCount;
+
+    fprintf(fp, "%u,", m_ImportCount);
+    fprintf(fp, "%u,", lateFailCount);
+    fprintf(fp, "%u,", m_InlineCount);
 }
 
 //------------------------------------------------------------------------
@@ -851,7 +931,7 @@ void InlineStrategy::NoteCandidate()
 //     context - context describing this inline
 //
 // Return Value:
-//    Nominal estimate of  jit time.
+//    Nominal estimate of jit time.
 
 int InlineStrategy::EstimateTime(InlineContext* context)
 {
@@ -945,10 +1025,9 @@ int InlineStrategy::EstimateSize(InlineContext* context)
 
 void InlineStrategy::NoteOutcome(InlineContext* context)
 {
-    // Might want to differentiate candidates from non-candidates here...
-    // We don't really attempt to inline non-candidates.
-    m_InlineAttemptCount++;
-
+    // Note we can't generally count up failures here -- we only
+    // create contexts for failures in debug modes, and even then
+    // we may not get them all.
     if (context->IsSuccess())
     {
         m_InlineCount++;

diff --git a/src/coreclr/src/jit/inline.h b/src/coreclr/src/jit/inline.h
index aa0573c..55671b3 100644 (file)
--- a/src/coreclr/src/jit/inline.h
+++ b/src/coreclr/src/jit/inline.h
@@ -400,7 +400,7 @@ public:
     // Determine if this inline is profitable
     void DetermineProfitability(CORINFO_METHOD_INFO* methodInfo)
     {
-        return m_Policy->DetermineProfitability(methodInfo);
+        m_Policy->DetermineProfitability(methodInfo);
     }
 
     // Ensure details of this inlining process are appropriately
@@ -751,8 +751,40 @@ public:
         return m_InitialSizeEstimate;
     }
 
+    // Inform strategy that there's another call
+    void NoteCall()
+    {
+        m_CallCount++;
+    }
+
     // Inform strategy that there's a new inline candidate.
-    void NoteCandidate();
+    void NoteCandidate()
+    {
+        m_CandidateCount++;
+    }
+
+    // Inform strategy that a candidate was assessed and determined to
+    // be unprofitable.
+    void NoteUnprofitable()
+    {
+        m_UnprofitableCandidateCount++;
+    }
+
+    // Inform strategy that a candidate has passed screening
+    // and that the jit will attempt to inline.
+    void NoteAttempt(InlineResult* result);
+
+    // Inform strategy that jit is about to import the inlinee IL.
+    void NoteImport()
+    {
+        m_ImportCount++;
+    }
+
+    // Dump csv header for inline stats to indicated file.
+    static void DumpCsvHeader(FILE* f);
+
+    // Dump csv data for inline stats to indicated file.
+    void DumpCsvData(FILE* f);
 
     // See if an inline of this size would fit within the current jit
     // time budget.
@@ -834,8 +866,13 @@ private:
     InlineContext* m_RootContext;
     InlinePolicy*  m_LastSuccessfulPolicy;
     InlineContext* m_LastContext;
+    unsigned       m_CallCount;
     unsigned       m_CandidateCount;
-    unsigned       m_InlineAttemptCount;
+    unsigned       m_AlwaysCandidateCount;
+    unsigned       m_ForceCandidateCount;
+    unsigned       m_DiscretionaryCandidateCount;
+    unsigned       m_UnprofitableCandidateCount;
+    unsigned       m_ImportCount;
     unsigned       m_InlineCount;
     unsigned       m_MaxInlineSize;
     unsigned       m_MaxInlineDepth;

diff --git a/src/coreclr/src/jit/morph.cpp b/src/coreclr/src/jit/morph.cpp
index 5572d8c..c7fcabb 100755 (executable)
--- a/src/coreclr/src/jit/morph.cpp
+++ b/src/coreclr/src/jit/morph.cpp
@@ -6516,6 +6516,8 @@ void Compiler::fgMorphCallInlineHelper(GenTreeCall* call, InlineResult* result)
     }
 #endif
 
+    impInlineRoot()->m_inlineStrategy->NoteAttempt(result);
+
     //
     // Invoke the compiler to inline the call.
     //