ART: Log information when skipping method during compilation

Add a reason for skipping a method to the log.

Change-Id: I3b31ee64cce6b531b25397f646cdfee650704ad6

3 files changed, 32 insertions, 15 deletions

diff --git a/compiler/dex/frontend.cc b/compiler/dex/frontend.cc
index b8d190a..c02d089 100644
--- a/compiler/dex/frontend.cc
+++ b/compiler/dex/frontend.cc
@@ -897,8 +897,8 @@ static CompiledMethod* CompileMethod(CompilerDriver& driver,
   // Check early if we should skip this compilation if the profiler is enabled.
   if (cu.compiler_driver->ProfilePresent()) {
     std::string methodname = PrettyMethod(method_idx, dex_file);
-    if (cu.mir_graph->SkipCompilation(methodname)) {
-      return NULL;
+    if (cu.mir_graph->SkipCompilationByName(methodname)) {
+      return nullptr;
     }
   }
 
@@ -908,13 +908,16 @@ static CompiledMethod* CompileMethod(CompilerDriver& driver,
 
   // TODO(Arm64): Remove this when we are able to compile everything.
   if (!CanCompileMethod(method_idx, dex_file, cu)) {
-    VLOG(compiler) << "Cannot compile method : " << PrettyMethod(method_idx, dex_file);
+    VLOG(compiler)  << cu.instruction_set << ": Cannot compile method : "
+                    << PrettyMethod(method_idx, dex_file);
     return nullptr;
   }
 
   cu.NewTimingSplit("MIROpt:CheckFilters");
-  if (cu.mir_graph->SkipCompilation()) {
-    VLOG(compiler) << "Skipping method : " << PrettyMethod(method_idx, dex_file);
+  std::string skip_message;
+  if (cu.mir_graph->SkipCompilation(&skip_message)) {
+    VLOG(compiler) << cu.instruction_set << ": Skipping method : "
+                   << PrettyMethod(method_idx, dex_file) << "  Reason = " << skip_message;
     return nullptr;
   }
 
@@ -945,7 +948,9 @@ static CompiledMethod* CompileMethod(CompilerDriver& driver,
   CompiledMethod* result = NULL;
 
   if (cu.mir_graph->PuntToInterpreter()) {
-    return NULL;
+    VLOG(compiler) << cu.instruction_set << ": Punted method to interpreter: "
+                   << PrettyMethod(method_idx, dex_file);
+    return nullptr;
   }
 
   cu.cg->Materialize();
@@ -955,9 +960,9 @@ static CompiledMethod* CompileMethod(CompilerDriver& driver,
   cu.NewTimingSplit("Cleanup");
 
   if (result) {
-    VLOG(compiler) << "Compiled " << PrettyMethod(method_idx, dex_file);
+    VLOG(compiler) << cu.instruction_set << ": Compiled " << PrettyMethod(method_idx, dex_file);
   } else {
-    VLOG(compiler) << "Deferred " << PrettyMethod(method_idx, dex_file);
+    VLOG(compiler) << cu.instruction_set << ": Deferred " << PrettyMethod(method_idx, dex_file);
   }
 
   if (cu.enable_debug & (1 << kDebugShowMemoryUsage)) {
diff --git a/compiler/dex/mir_analysis.cc b/compiler/dex/mir_analysis.cc
index 1350665..e372206 100644
--- a/compiler/dex/mir_analysis.cc
+++ b/compiler/dex/mir_analysis.cc
@@ -941,7 +941,8 @@ void MIRGraph::AnalyzeBlock(BasicBlock* bb, MethodStats* stats) {
   }
 }
 
-bool MIRGraph::ComputeSkipCompilation(MethodStats* stats, bool skip_default) {
+bool MIRGraph::ComputeSkipCompilation(MethodStats* stats, bool skip_default,
+                                      std::string* skip_message) {
   float count = stats->dex_instructions;
   stats->math_ratio = stats->math_ops / count;
   stats->fp_ratio = stats->fp_ops / count;
@@ -994,6 +995,8 @@ bool MIRGraph::ComputeSkipCompilation(MethodStats* stats, bool skip_default) {
   // If significant in size and high proportion of expensive operations, skip.
   if (cu_->compiler_driver->GetCompilerOptions().IsSmallMethod(GetNumDalvikInsns()) &&
       (stats->heavyweight_ratio > 0.3)) {
+    *skip_message = "Is a small method with heavyweight ratio " +
+                    std::to_string(stats->heavyweight_ratio);
     return true;
   }
 
@@ -1003,7 +1006,7 @@ bool MIRGraph::ComputeSkipCompilation(MethodStats* stats, bool skip_default) {
  /*
   * Will eventually want this to be a bit more sophisticated and happen at verification time.
   */
-bool MIRGraph::SkipCompilation() {
+bool MIRGraph::SkipCompilation(std::string* skip_message) {
   const CompilerOptions& compiler_options = cu_->compiler_driver->GetCompilerOptions();
   CompilerOptions::CompilerFilter compiler_filter = compiler_options.GetCompilerFilter();
   if (compiler_filter == CompilerOptions::kEverything) {
@@ -1012,10 +1015,12 @@ bool MIRGraph::SkipCompilation() {
 
   // Contains a pattern we don't want to compile?
   if (PuntToInterpreter()) {
+    *skip_message = "Punt to interpreter set";
     return true;
   }
 
   if (!compiler_options.IsCompilationEnabled()) {
+    *skip_message = "Compilation disabled";
     return true;
   }
 
@@ -1041,6 +1046,9 @@ bool MIRGraph::SkipCompilation() {
 
   // If size < cutoff, assume we'll compile - but allow removal.
   bool skip_compilation = (GetNumDalvikInsns() >= default_cutoff);
+  if (skip_compilation) {
+    *skip_message = "#Insns >= default_cutoff: " + std::to_string(GetNumDalvikInsns());
+  }
 
   /*
    * Filter 1: Huge methods are likely to be machine generated, but some aren't.
@@ -1048,6 +1056,7 @@ bool MIRGraph::SkipCompilation() {
    */
   if (compiler_options.IsHugeMethod(GetNumDalvikInsns())) {
     skip_compilation = true;
+    *skip_message = "Huge method: " + std::to_string(GetNumDalvikInsns());
     // If we're got a huge number of basic blocks, don't bother with further analysis.
     if (static_cast<size_t>(num_blocks_) > (compiler_options.GetHugeMethodThreshold() / 2)) {
       return true;
@@ -1055,6 +1064,7 @@ bool MIRGraph::SkipCompilation() {
   } else if (compiler_options.IsLargeMethod(GetNumDalvikInsns()) &&
     /* If it's large and contains no branches, it's likely to be machine generated initialization */
       (GetBranchCount() == 0)) {
+    *skip_message = "Large method with no branches";
     return true;
   } else if (compiler_filter == CompilerOptions::kSpeed) {
     // If not huge, compile.
@@ -1063,6 +1073,7 @@ bool MIRGraph::SkipCompilation() {
 
   // Filter 2: Skip class initializers.
   if (((cu_->access_flags & kAccConstructor) != 0) && ((cu_->access_flags & kAccStatic) != 0)) {
+    *skip_message = "Class initializer";
     return true;
   }
 
@@ -1092,7 +1103,7 @@ bool MIRGraph::SkipCompilation() {
     AnalyzeBlock(bb, &stats);
   }
 
-  return ComputeSkipCompilation(&stats, skip_compilation);
+  return ComputeSkipCompilation(&stats, skip_compilation, skip_message);
 }
 
 void MIRGraph::DoCacheFieldLoweringInfo() {
@@ -1285,7 +1296,7 @@ void MIRGraph::DoCacheMethodLoweringInfo() {
                                  method_lowering_infos_.GetRawStorage(), count);
 }
 
-bool MIRGraph::SkipCompilation(const std::string& methodname) {
+bool MIRGraph::SkipCompilationByName(const std::string& methodname) {
   return cu_->compiler_driver->SkipCompilation(methodname);
 }
 
diff --git a/compiler/dex/mir_graph.h b/compiler/dex/mir_graph.h
index 15c0aa4..0ff340e 100644
--- a/compiler/dex/mir_graph.h
+++ b/compiler/dex/mir_graph.h
@@ -559,12 +559,12 @@ class MIRGraph {
    * Examine the graph to determine whether it's worthwile to spend the time compiling
    * this method.
    */
-  bool SkipCompilation();
+  bool SkipCompilation(std::string* skip_message);
 
   /*
    * Should we skip the compilation of this method based on its name?
    */
-  bool SkipCompilation(const std::string& methodname);
+  bool SkipCompilationByName(const std::string& methodname);
 
   /*
    * Parse dex method and add MIR at current insert point.  Returns id (which is
@@ -1127,7 +1127,8 @@ class MIRGraph {
 
   void CountChecks(BasicBlock* bb);
   void AnalyzeBlock(BasicBlock* bb, struct MethodStats* stats);
-  bool ComputeSkipCompilation(struct MethodStats* stats, bool skip_default);
+  bool ComputeSkipCompilation(struct MethodStats* stats, bool skip_default,
+                              std::string* skip_message);
 
   CompilationUnit* const cu_;
   GrowableArray<int>* ssa_base_vregs_;