Incremental tuning/cleanup of inlining: --print-inline-tree changed to --print-inlining-tree.

runtime/vm/flow_graph_inliner.cc

 // Copyright (c) 2013, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 
 #include "vm/flow_graph_inliner.h"
 
 #include "vm/block_scheduler.h"
 #include "vm/compiler.h"
 #include "vm/flags.h"
 #include "vm/flow_graph.h"
@@ skipping 29 matching lines @@
     "Inline function calls with sufficient constant arguments "
     "and up to the increased threshold on instructions");
 DEFINE_FLAG(int, inlining_constant_arguments_size_threshold, 60,
     "Inline function calls with sufficient constant arguments "
     "and up to the increased threshold on instructions");
 DEFINE_FLAG(int, inlining_hotness, 10,
     "Inline only hotter calls, in percents (0 .. 100); "
     "default 10%: calls above-equal 10% of max-count are inlined.");
 DEFINE_FLAG(bool, inline_recursive, true,
     "Inline recursive calls.");
-DEFINE_FLAG(bool, print_inline_tree, false, "Print inlining tree");
+DEFINE_FLAG(bool, print_inlining_tree, false, "Print inlining tree");
 
 DECLARE_FLAG(bool, print_flow_graph);
 DECLARE_FLAG(bool, print_flow_graph_optimized);
 DECLARE_FLAG(int, deoptimization_counter_threshold);
 DECLARE_FLAG(bool, verify_compiler);
 DECLARE_FLAG(bool, compiler_stats);
 
 #define TRACE_INLINING(statement)                                              \
   do {                                                                         \
     if (FLAG_trace_inlining) statement;                                        \
@@ skipping 68 matching lines @@
           continue;
         }
         if (current->IsPolymorphicInstanceCall()) {
           PolymorphicInstanceCallInstr* call =
               current->AsPolymorphicInstanceCall();
           // These checks make sure that the number of call-sites counted does
           // not change relative to the time when the current set of inlining
           // parameters was fixed.
           // TODO(fschneider): Determine new heuristic parameters that avoid
           // these checks entirely.
-          if (!call->HasRecognizedTarget() &&
+          if (!call->HasSingleRecognizedTarget() &&
               (call->instance_call()->token_kind() != Token::kEQ)) {
             ++call_site_count_;
           }
         }
       }
     }
   }
 
   intptr_t call_site_count() const { return call_site_count_; }
   intptr_t instruction_count() const { return instruction_count_; }
 
  private:
   intptr_t call_site_count_;
   intptr_t instruction_count_;
 };
 
 
+// Structure for collecting inline data needed to print inlining tree.
+struct InlinedInfo {
+  const Function* caller;
+  const Function* inlined;
+  intptr_t inlined_depth;
+  const Definition* call_instr;
+  const char* bailout_reason;
+  InlinedInfo(const Function* caller_function,
+              const Function* inlined_function,
+              const intptr_t depth,
+              const Definition* call,
+              const char* reason = NULL)
+      : caller(caller_function),
+        inlined(inlined_function),
+        inlined_depth(depth),
+        call_instr(call),
+        bailout_reason(reason) {}
+};
+
+
 // A collection of call sites to consider for inlining.
 class CallSites : public ValueObject {
  public:
   explicit CallSites(FlowGraph* flow_graph)
       : static_calls_(),
         closure_calls_(),
         instance_calls_() { }
 
   struct InstanceCallInfo {
     PolymorphicInstanceCallInstr* call;
@@ skipping 80 matching lines @@
           0.0 : static_cast<double>(instance_call_counts[i]) / max_count;
       instance_calls_[i + instance_call_start_ix].ratio = ratio;
     }
     for (intptr_t i = 0; i < num_static_calls; ++i) {
       const double ratio = (max_count == 0) ?
           0.0 : static_cast<double>(static_call_counts[i]) / max_count;
       static_calls_[i + static_call_start_ix].ratio = ratio;
     }
   }
 
-  void FindCallSites(FlowGraph* graph, intptr_t depth) {
+  void FindCallSites(FlowGraph* graph,
+                     intptr_t depth,
+                     GrowableArray<InlinedInfo>* inlined_info) {
     ASSERT(graph != NULL);
-    // If depth is less than the threshold recursively add call sites.
+
     if (depth > FLAG_inlining_depth_threshold) return;
 
     // Recognized methods are not treated as normal calls. They don't have
     // calls in themselves, so we keep adding those even when at the threshold.
     const bool only_recognized_methods =

[Cutch, 2014/03/26 20:26:37]

Could this be renamed? It was confusing that you do:

if (!only_recognized_methods ...) {
   ...InlineInfo(..., "Too deep");
}

[srdjan, 2014/03/26 21:05:31]

Renamed to inline_only_recognized_methods, added comments.

         (depth == FLAG_inlining_depth_threshold);
 
     const intptr_t instance_call_start_ix = instance_calls_.length();
     const intptr_t static_call_start_ix = static_calls_.length();
     for (BlockIterator block_it = graph->postorder_iterator();
          !block_it.Done();
          block_it.Advance()) {
       for (ForwardInstructionIterator it(block_it.Current());
            !it.Done();
            it.Advance()) {
         Instruction* current = it.Current();
-        if (only_recognized_methods) {
+        if (current->IsPolymorphicInstanceCall()) {
           PolymorphicInstanceCallInstr* instance_call =
               current->AsPolymorphicInstanceCall();
-          if ((instance_call != NULL) && instance_call->HasRecognizedTarget()) {
+          if (!only_recognized_methods ||
+              instance_call->HasSingleRecognizedTarget()) {
             instance_calls_.Add(InstanceCallInfo(instance_call, graph));
+          } else {
+            if (FLAG_print_inlining_tree) {
+              const Function* caller = &graph->parsed_function().function();
+              const Function* target =
+                  &Function::ZoneHandle(
+                      instance_call->ic_data().GetTargetAt(0));
+              inlined_info->Add(InlinedInfo(
+                  caller, target, depth, instance_call, "Too deep"));
+            }
           }
-          continue;
-        }
-        // Collect all call sites (!only_recognized_methods).
-        ClosureCallInstr* closure_call = current->AsClosureCall();
-        if (closure_call != NULL) {
-          closure_calls_.Add(ClosureCallInfo(closure_call, graph));
-          continue;
-        }
-        StaticCallInstr* static_call = current->AsStaticCall();
-        if (static_call != NULL) {
-          static_calls_.Add(StaticCallInfo(static_call, graph));
-          continue;
-        }
-        PolymorphicInstanceCallInstr* instance_call =
-            current->AsPolymorphicInstanceCall();
-        if (instance_call != NULL) {
-          instance_calls_.Add(InstanceCallInfo(instance_call, graph));
-          continue;
+        } else if (current->IsStaticCall()) {
+          StaticCallInstr* static_call = current->AsStaticCall();
+          if (!only_recognized_methods ||
+              static_call->function().is_recognized()) {
+            static_calls_.Add(StaticCallInfo(static_call, graph));
+          } else {
+            if (FLAG_print_inlining_tree) {
+              const Function* caller = &graph->parsed_function().function();
+              const Function* target = &static_call->function();
+              inlined_info->Add(InlinedInfo(
+                  caller, target, depth, static_call, "Too deep"));
+            }
+          }
+        } else if (current->IsClosureCall()) {
+          if (!only_recognized_methods) {
+            ClosureCallInstr* closure_call = current->AsClosureCall();
+            closure_calls_.Add(ClosureCallInfo(closure_call, graph));
+          }
         }
       }
     }
     ComputeCallSiteRatio(static_call_start_ix, instance_call_start_ix);
   }
 
  private:
   GrowableArray<StaticCallInfo> static_calls_;
   GrowableArray<ClosureCallInfo> closure_calls_;
   GrowableArray<InstanceCallInfo> instance_calls_;
 
   DISALLOW_COPY_AND_ASSIGN(CallSites);
 };
 
 
 struct InlinedCallData {
   InlinedCallData(Definition* call,
                   GrowableArray<Value*>* arguments,
                   const Function& caller)
       : call(call),
         arguments(arguments),
         callee_graph(NULL),
         parameter_stubs(NULL),
         exit_collector(NULL),
-        caller_(caller) { }
+        caller(caller) { }
 
   Definition* call;
   GrowableArray<Value*>* arguments;
   FlowGraph* callee_graph;
   ZoneGrowableArray<Definition*>* parameter_stubs;
   InlineExitCollector* exit_collector;
-  const Function& caller_;
-};
-
-
-// Structure for collecting inline data needed to print inlining tree.
-struct InlinedInfo {
-  const Function* caller;
-  const Function* inlined;
-  intptr_t inlined_depth;
-  const Definition* call_instr;
-  InlinedInfo(const Function* caller_function,
-              const Function* inlined_function,
-              const intptr_t depth,
-              const Definition* call)
-      : caller(caller_function),
-        inlined(inlined_function),
-        inlined_depth(depth),
-        call_instr(call) {}
+  const Function& caller;
 };
 
 
 class CallSiteInliner;
 
 class PolymorphicInliner : public ValueObject {
  public:
   PolymorphicInliner(CallSiteInliner* owner,
                      PolymorphicInstanceCallInstr* call,
                      const Function& caller_function);
@@ skipping 71 matching lines @@
         FLAG_deoptimization_counter_inlining_threshold) {
       return;
     }
     // Create two call site collections to swap between.
     CallSites sites1(caller_graph_);
     CallSites sites2(caller_graph_);
     CallSites* call_sites_temp = NULL;
     collected_call_sites_ = &sites1;
     inlining_call_sites_ = &sites2;
     // Collect initial call sites.
-    collected_call_sites_->FindCallSites(caller_graph_, inlining_depth_);
+    collected_call_sites_->FindCallSites(caller_graph_,
+                                         inlining_depth_,
+                                         &inlined_info_);
     while (collected_call_sites_->HasCalls()) {
       TRACE_INLINING(OS::Print("  Depth %" Pd " ----------\n",
                                inlining_depth_));
       // Swap collected and inlining arrays and clear the new collecting array.
       call_sites_temp = collected_call_sites_;
       collected_call_sites_ = inlining_call_sites_;
       inlining_call_sites_ = call_sites_temp;
       collected_call_sites_->Clear();
       // Inline call sites at the current depth.
       InlineStaticCalls();
@@ skipping 17 matching lines @@
                    const Array& argument_names,
                    InlinedCallData* call_data) {
     TRACE_INLINING(OS::Print("  => %s (deopt count %d)\n",
                              function.ToCString(),
                              function.deoptimization_counter()));
 
     // TODO(fschneider): Enable inlining inside try-blocks.
     if (call_data->call->GetBlock()->try_index() !=
         CatchClauseNode::kInvalidTryIndex) {
       TRACE_INLINING(OS::Print("     Bailout: inside try-block\n"));
+      if (FLAG_print_inlining_tree) {
+        inlined_info_.Add(InlinedInfo(
+            &call_data->caller, &function, inlining_depth_, call_data->call,
+            "Inside try-block"));
+      }
       return false;
     }
 
     // Make a handle for the unoptimized code so that it is not disconnected
     // from the function while we are trying to inline it.
     const Code& unoptimized_code = Code::Handle(function.unoptimized_code());
     // Abort if the inlinable bit on the function is low.
     if (!function.IsInlineable()) {
       TRACE_INLINING(OS::Print("     Bailout: not inlinable\n"));
+      if (FLAG_print_inlining_tree) {
+        inlined_info_.Add(InlinedInfo(
+            &call_data->caller, &function, inlining_depth_, call_data->call,
+            "Not inlinable"));
+      }
       return false;
     }
 
     // Abort if this function has deoptimized too much.
     if (function.deoptimization_counter() >=
         FLAG_deoptimization_counter_threshold) {
       function.set_is_inlinable(false);
       TRACE_INLINING(OS::Print("     Bailout: deoptimization threshold\n"));
+      if (FLAG_print_inlining_tree) {
+        inlined_info_.Add(InlinedInfo(
+            &call_data->caller, &function, inlining_depth_, call_data->call,
+            "Deoptimization threshold exceeded"));
+      }
       return false;
     }
 
     GrowableArray<Value*>* arguments = call_data->arguments;
     const intptr_t constant_arguments = CountConstants(*arguments);
     if (!ShouldWeInline(function,
                         function.optimized_instruction_count(),
                         function.optimized_call_site_count(),
                         constant_arguments)) {
       TRACE_INLINING(OS::Print("     Bailout: early heuristics with "
                                "code size:  %" Pd ", "
                                "call sites: %" Pd ", "
                                "const args: %" Pd "\n",
                                function.optimized_instruction_count(),
                                function.optimized_call_site_count(),
                                constant_arguments));
+      if (FLAG_print_inlining_tree) {
+        inlined_info_.Add(InlinedInfo(
+            &call_data->caller, &function, inlining_depth_, call_data->call,
+            "Early heuristic"));
+      }
       return false;
     }
 
     // Abort if this is a recursive occurrence.
     Definition* call = call_data->call;
     if (!FLAG_inline_recursive && IsCallRecursive(unoptimized_code, call)) {
       function.set_is_inlinable(false);
       TRACE_INLINING(OS::Print("     Bailout: recursive function\n"));
       return false;
     }
@@ skipping 106 matching lines @@
         FlowGraphPrinter printer(*callee_graph);
         printer.PrintBlocks();
       }
 
       // Collect information about the call site and caller graph.
       // TODO(zerny): Do this after CP and dead code elimination.
       intptr_t constants_count = 0;
       for (intptr_t i = 0; i < param_stubs->length(); ++i) {
         if ((*param_stubs)[i]->IsConstant()) ++constants_count;
       }
-      GraphInfoCollector info;
-      info.Collect(*callee_graph);
-      const intptr_t size = info.instruction_count();
-      const intptr_t call_site_count = info.call_site_count();
+
+      FlowGraphInliner::CollectGraphInfo(callee_graph);
+      const intptr_t size = function.optimized_instruction_count();
+      const intptr_t call_site_count = function.optimized_call_site_count();
 
       function.set_optimized_instruction_count(size);
       function.set_optimized_call_site_count(call_site_count);
 
       // Use heuristics do decide if this call should be inlined.
       if (!ShouldWeInline(function, size, call_site_count, constants_count)) {
         // If size is larger than all thresholds, don't consider it again.
         if ((size > FLAG_inlining_size_threshold) &&
             (call_site_count > FLAG_inlining_callee_call_sites_threshold) &&
             (size > FLAG_inlining_constant_arguments_size_threshold)) {
           function.set_is_inlinable(false);
         }
         isolate->set_deopt_id(prev_deopt_id);
         TRACE_INLINING(OS::Print("     Bailout: heuristics with "
                                  "code size:  %" Pd ", "
                                  "call sites: %" Pd ", "
                                  "const args: %" Pd "\n",
                                  size,
                                  call_site_count,
                                  constants_count));
+        if (FLAG_print_inlining_tree) {
+          inlined_info_.Add(InlinedInfo(
+              &call_data->caller, &function, inlining_depth_, call_data->call,
+              "Heuristic fail"));
+        }
         return false;
       }
 
-      collected_call_sites_->FindCallSites(callee_graph, inlining_depth_);
+      collected_call_sites_->FindCallSites(callee_graph,
+                                           inlining_depth_,
+                                           &inlined_info_);
 
       // Add the function to the cache.
       if (!in_cache) {
         function_cache_.Add(parsed_function);
       }
 
       // Build succeeded so we restore the bailout jump.
       inlined_ = true;
       inlined_size_ += size;
       isolate->set_deopt_id(prev_deopt_id);
 
       call_data->callee_graph = callee_graph;
       call_data->parameter_stubs = param_stubs;
       call_data->exit_collector = exit_collector;
 
       // When inlined, we add the guarded fields of the callee to the caller's
       // list of guarded fields.
       for (intptr_t i = 0; i < callee_graph->guarded_fields()->length(); ++i) {
         FlowGraph::AddToGuardedFields(caller_graph_->guarded_fields(),
                                       (*callee_graph->guarded_fields())[i]);
       }
 
       // We allocate a ZoneHandle for the unoptimized code so that it cannot be
       // disconnected from its function during the rest of compilation.
       Code::ZoneHandle(unoptimized_code.raw());
       TRACE_INLINING(OS::Print("     Success\n"));
-      if (FLAG_print_inline_tree) {
+      if (FLAG_print_inlining_tree) {
         inlined_info_.Add(
-            InlinedInfo(&call_data->caller_, &function, inlining_depth_, call));
+            InlinedInfo(&call_data->caller, &function, inlining_depth_, call));
       }
       return true;
     } else {
       Error& error = Error::Handle();
       error = isolate->object_store()->sticky_error();
       isolate->object_store()->clear_sticky_error();
       isolate->set_deopt_id(prev_deopt_id);
       TRACE_INLINING(OS::Print("     Bailout: %s\n", error.ToErrorCString()));
       return false;
     }
   }
 
   void PrintInlinedInfo(const Function& top) {
-    OS::Print("Inlining into: %s\n", top.ToFullyQualifiedCString());
-    PrintInlinedInfoFor(top, 1);
+    if (inlined_info_.length() > 0) {
+      OS::Print("Inlining into: '%s' growth: %f (%"Pd" -> %"Pd")\n",
+          top.ToFullyQualifiedCString(),
+          GrowthFactor(),
+          initial_size_,
+          inlined_size_);
+      PrintInlinedInfoFor(top, 1);
+    }
   }
 
  private:
   friend class PolymorphicInliner;
 
   void PrintInlinedInfoFor(const Function& caller, intptr_t depth) {
+    // Print those that were inlined.
     for (intptr_t i = 0; i < inlined_info_.length(); i++) {
       const InlinedInfo& info = inlined_info_[i];
+      if (info.bailout_reason != NULL) continue;
       if ((info.inlined_depth == depth) &&
           (info.caller->raw() == caller.raw())) {
         for (int t = 0; t < depth; t++) {
           OS::Print("  ");
         }
         OS::Print("%" Pd " %s\n",
             info.call_instr->GetDeoptId(),
             info.inlined->ToQualifiedCString());
         PrintInlinedInfoFor(*info.inlined, depth + 1);
       }
     }
+    // Print those that were not inlined.
+    for (intptr_t i = 0; i < inlined_info_.length(); i++) {
+      const InlinedInfo& info = inlined_info_[i];
+      if (info.bailout_reason == NULL) continue;
+      if ((info.inlined_depth == depth) &&
+          (info.caller->raw() == caller.raw())) {
+        for (int t = 0; t < depth; t++) {
+          OS::Print("  ");
+        }
+        OS::Print("NO %" Pd " %s - %s\n",
+            info.call_instr->GetDeoptId(),
+            info.inlined->ToQualifiedCString(),
+            info.bailout_reason);
+      }
+    }
   }
 
   void InlineCall(InlinedCallData* call_data) {
     TimerScope timer(FLAG_compiler_stats,
                      &CompilerStats::graphinliner_subst_timer,
                      Isolate::Current());
 
     // For closure calls: Store context value.
     FlowGraph* callee_graph = call_data->callee_graph;
     TargetEntryInstr* callee_entry =
@@ skipping 98 matching lines @@
         }
       }
       const Function& target = call->function();
       if (!FlowGraphInliner::AlwaysInline(target) &&
           (call_info[call_idx].ratio * 100) < FLAG_inlining_hotness) {
         TRACE_INLINING(OS::Print(
             "  => %s (deopt count %d)\n     Bailout: cold %f\n",
             target.ToCString(),
             target.deoptimization_counter(),
             call_info[call_idx].ratio));
+        if (FLAG_print_inlining_tree) {
+          inlined_info_.Add(InlinedInfo(
+              call_info[call_idx].caller,
+              &call->function(),
+              inlining_depth_,
+              call,
+              "Too cold"));
+        }
         continue;
       }
       GrowableArray<Value*> arguments(call->ArgumentCount());
       for (int i = 0; i < call->ArgumentCount(); ++i) {
         arguments.Add(call->PushArgumentAt(i)->value());
       }
       InlinedCallData call_data(call, &arguments, *call_info[call_idx].caller);
       if (TryInlining(call->function(), call->argument_names(), &call_data)) {
         InlineCall(&call_data);
       }
@@ skipping 49 matching lines @@
 
       const ICData& ic_data = call->ic_data();
       const Function& target = Function::ZoneHandle(ic_data.GetTargetAt(0));
       if (!FlowGraphInliner::AlwaysInline(target) &&
           (call_info[call_idx].ratio * 100) < FLAG_inlining_hotness) {
         TRACE_INLINING(OS::Print(
             "  => %s (deopt count %d)\n     Bailout: cold %f\n",
             target.ToCString(),
             target.deoptimization_counter(),
             call_info[call_idx].ratio));
+        if (FLAG_print_inlining_tree) {
+          inlined_info_.Add(InlinedInfo(
+              call_info[call_idx].caller,
+              &target,
+              inlining_depth_,
+              call,
+              "Too cold"));
+        }
         continue;
       }
       GrowableArray<Value*> arguments(call->ArgumentCount());
       for (int arg_i = 0; arg_i < call->ArgumentCount(); ++arg_i) {
         arguments.Add(call->PushArgumentAt(arg_i)->value());
       }
       InlinedCallData call_data(call, &arguments, *call_info[call_idx].caller);
       if (TryInlining(target,
                       call->instance_call()->argument_names(),
                       &call_data)) {
@@ skipping 89 matching lines @@
       } else {
         param_stubs->Add(
             GetDefaultValue(i - fixed_param_count, parsed_function));
       }
     }
     return argument_names_count == match_count;
   }
 
   FlowGraph* caller_graph_;
   bool inlined_;
-  intptr_t initial_size_;
+  const intptr_t initial_size_;
   intptr_t inlined_size_;
   intptr_t inlining_depth_;
   CallSites* collected_call_sites_;
   CallSites* inlining_call_sites_;
   GrowableArray<ParsedFunction*> function_cache_;
   GrowableArray<InlinedInfo> inlined_info_;
 
   DISALLOW_COPY_AND_ASSIGN(CallSiteInliner);
 };
 
@@ skipping 454 matching lines @@
   TargetEntryInstr* entry = BuildDecisionGraph();
   exit_collector_->ReplaceCall(entry);
 }
 
 
 static uint16_t ClampUint16(intptr_t v) {
   return (v > 0xFFFF) ? 0xFFFF : static_cast<uint16_t>(v);
 }
 
 
-void FlowGraphInliner::CollectGraphInfo(FlowGraph* flow_graph) {
-  GraphInfoCollector info;
-  info.Collect(*flow_graph);
+void FlowGraphInliner::CollectGraphInfo(FlowGraph* flow_graph, bool force) {
   const Function& function = flow_graph->parsed_function().function();
-  function.set_optimized_instruction_count(
-      ClampUint16(info.instruction_count()));
-  function.set_optimized_call_site_count(ClampUint16(info.call_site_count()));
+  if (force || (function.optimized_instruction_count() == 0)) {
+    GraphInfoCollector info;
+    info.Collect(*flow_graph);
+
+    function.set_optimized_instruction_count(
+        ClampUint16(info.instruction_count()));
+    function.set_optimized_call_site_count(ClampUint16(info.call_site_count()));
+  }
 }
 
 
 bool FlowGraphInliner::AlwaysInline(const Function& function) {
   if (function.IsImplicitGetterFunction() || function.IsGetterFunction() ||
       function.IsImplicitSetterFunction() || function.IsSetterFunction()) {
     const intptr_t count = function.optimized_instruction_count();
     if ((count != 0) && (count < FLAG_inline_getters_setters_smaller_than)) {
       return true;
     }
@@ skipping 18 matching lines @@
   if (FLAG_trace_inlining &&
       (FLAG_print_flow_graph || FLAG_print_flow_graph_optimized)) {
     OS::Print("Before Inlining of %s\n", flow_graph_->
               parsed_function().function().ToFullyQualifiedCString());
     FlowGraphPrinter printer(*flow_graph_);
     printer.PrintBlocks();
   }
 
   CallSiteInliner inliner(flow_graph_);
   inliner.InlineCalls();
-  if (FLAG_print_inline_tree) {
+  if (FLAG_print_inlining_tree) {
     inliner.PrintInlinedInfo(top);
   }
 
   if (inliner.inlined()) {
     flow_graph_->DiscoverBlocks();
     if (FLAG_trace_inlining) {
       OS::Print("Inlining growth factor: %f\n", inliner.GrowthFactor());
       if (FLAG_print_flow_graph || FLAG_print_flow_graph_optimized) {
         OS::Print("After Inlining of %s\n", flow_graph_->
                   parsed_function().function().ToFullyQualifiedCString());
         FlowGraphPrinter printer(*flow_graph_);
         printer.PrintBlocks();
       }
     }
   }
 }
 
 }  // namespace dart