Migrate logging infrastructure Isolate->Thread

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 545 matching lines @@
     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_,
                                          &inlined_info_);
     while (collected_call_sites_->HasCalls()) {
-      TRACE_INLINING(ISL_Print("  Depth %" Pd " ----------\n",
+      TRACE_INLINING(THR_Print("  Depth %" Pd " ----------\n",
                                inlining_depth_));
       if (collected_call_sites_->NumCalls() > FLAG_max_inlined_per_depth) {
         break;
       }
       if (FLAG_print_inlining_tree) {
-        ISL_Print("**Depth % " Pd " calls to inline %" Pd "\n",
+        THR_Print("**Depth % " Pd " calls to inline %" Pd "\n",
             inlining_depth_, collected_call_sites_->NumCalls());
       }
       // 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.
       InlineInstanceCalls();
       InlineStaticCalls();
@@ skipping 24 matching lines @@
     if (constant != NULL) {
       return new(Z) ConstantInstr(constant->value());
     } else {
       return new(Z) ParameterInstr(i, graph->graph_entry());
     }
   }
 
   bool TryInlining(const Function& function,
                    const Array& argument_names,
                    InlinedCallData* call_data) {
-    TRACE_INLINING(ISL_Print("  => %s (deopt count %d)\n",
+    TRACE_INLINING(THR_Print("  => %s (deopt count %d)\n",
                              function.ToCString(),
                              function.deoptimization_counter()));
 
     // 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.CanBeInlined()) {
-      TRACE_INLINING(ISL_Print("     Bailout: not inlinable\n"));
+      TRACE_INLINING(THR_Print("     Bailout: not inlinable\n"));
       PRINT_INLINING_TREE("Not inlinable",
           &call_data->caller, &function, call_data->call);
       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(ISL_Print("     Bailout: deoptimization threshold\n"));
+      TRACE_INLINING(THR_Print("     Bailout: deoptimization threshold\n"));
       PRINT_INLINING_TREE("Deoptimization threshold exceeded",
           &call_data->caller, &function, call_data->call);
       return false;
     }
 
     const char* kNeverInlineAnnotation = "NeverInline";
     if (FLAG_enable_inlining_annotations &&
         HasAnnotation(function, kNeverInlineAnnotation)) {
-      TRACE_INLINING(ISL_Print("     Bailout: NeverInline annotation\n"));
+      TRACE_INLINING(THR_Print("     Bailout: NeverInline annotation\n"));
       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(ISL_Print("     Bailout: early heuristics with "
+      TRACE_INLINING(THR_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));
       PRINT_INLINING_TREE("Early heuristic",
           &call_data->caller, &function, call_data->call);
       return false;
     }
 
     // Abort if this is a recursive occurrence.
     Definition* call = call_data->call;
     // Added 'volatile' works around a possible GCC 4.9 compiler bug.
     volatile bool is_recursive_call = IsCallRecursive(function, call);
     if (is_recursive_call &&
         inlining_recursion_depth_ >= FLAG_inlining_recursion_depth_threshold) {
-      TRACE_INLINING(ISL_Print("     Bailout: recursive function\n"));
+      TRACE_INLINING(THR_Print("     Bailout: recursive function\n"));
       PRINT_INLINING_TREE("Recursive function",
           &call_data->caller, &function, call_data->call);
       return false;
     }
 
     // Save and clear deopt id.
     const intptr_t prev_deopt_id = isolate()->deopt_id();
     isolate()->set_deopt_id(0);
     // Install bailout jump.
     LongJumpScope jump;
@@ skipping 42 matching lines @@
 
       // Create a parameter stub for each fixed positional parameter.
       for (intptr_t i = 0; i < function.num_fixed_parameters(); ++i) {
         param_stubs->Add(CreateParameterStub(i, (*arguments)[i], callee_graph));
       }
 
       // If the callee has optional parameters, rebuild the argument and stub
       // arrays so that actual arguments are in one-to-one with the formal
       // parameters.
       if (function.HasOptionalParameters()) {
-        TRACE_INLINING(ISL_Print("     adjusting for optional parameters\n"));
+        TRACE_INLINING(THR_Print("     adjusting for optional parameters\n"));
         if (!AdjustForOptionalParameters(*parsed_function,
                                          argument_names,
                                          arguments,
                                          param_stubs,
                                          callee_graph)) {
           function.set_is_inlinable(false);
-          TRACE_INLINING(ISL_Print("     Bailout: optional arg mismatch\n"));
+          TRACE_INLINING(THR_Print("     Bailout: optional arg mismatch\n"));
           PRINT_INLINING_TREE("Optional arg mismatch",
               &call_data->caller, &function, call_data->call);
           return false;
         }
       }
 
       // After treating optional parameters the actual/formal count must match.
       ASSERT(arguments->length() == function.NumParameters());
       ASSERT(param_stubs->length() == callee_graph->parameter_count());
 
@@ skipping 30 matching lines @@
         DEBUG_ASSERT(callee_graph->VerifyUseLists());
 
         // Optimize (a << b) & c patterns, merge instructions. Must occur before
         // 'SelectRepresentations' which inserts conversion nodes.
         optimizer.TryOptimizePatterns();
         DEBUG_ASSERT(callee_graph->VerifyUseLists());
       }
 
       if (FLAG_trace_inlining &&
           (FLAG_print_flow_graph || FLAG_print_flow_graph_optimized)) {
-        ISL_Print("Callee graph for inlining %s\n",
+        THR_Print("Callee graph for inlining %s\n",
                   function.ToFullyQualifiedCString());
         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;
       }
 
       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_min_size_threshold) &&
             (size > FLAG_inlining_constant_arguments_max_size_threshold)) {
           function.set_is_inlinable(false);
         }
         isolate()->set_deopt_id(prev_deopt_id);
-        TRACE_INLINING(ISL_Print("     Bailout: heuristics with "
+        TRACE_INLINING(THR_Print("     Bailout: heuristics with "
                                  "code size:  %" Pd ", "
                                  "call sites: %" Pd ", "
                                  "const args: %" Pd "\n",
                                  size,
                                  call_site_count,
                                  constants_count));
         PRINT_INLINING_TREE("Heuristic fail",
             &call_data->caller, &function, call_data->call);
         return false;
       }
@@ skipping 30 matching lines @@
       // When inlined, we add the deferred prefixes of the callee to the
       // caller's list of deferred prefixes.
       caller_graph()->AddToDeferredPrefixes(callee_graph->deferred_prefixes());
 
       FlowGraphInliner::SetInliningId(callee_graph,
           inliner_->NextInlineId(callee_graph->function(),
                                  call_data->caller_inlining_id_));
       // 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(ISL_Print("     Success\n"));
+      TRACE_INLINING(THR_Print("     Success\n"));
       PRINT_INLINING_TREE(NULL,
           &call_data->caller, &function, 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(ISL_Print("     Bailout: %s\n", error.ToErrorCString()));
+      TRACE_INLINING(THR_Print("     Bailout: %s\n", error.ToErrorCString()));
       PRINT_INLINING_TREE("Bailout",
           &call_data->caller, &function, call);
       return false;
     }
   }
 
   void PrintInlinedInfo(const Function& top) {
     if (inlined_info_.length() > 0) {
-      ISL_Print("Inlining into: '%s' growth: %f (%" Pd " -> %" Pd ")\n",
+      THR_Print("Inlining into: '%s' growth: %f (%" Pd " -> %" Pd ")\n",
           top.ToFullyQualifiedCString(),
           GrowthFactor(),
           initial_size_,
           inlined_size_);
       PrintInlinedInfoFor(top, 1);
     }
   }
 
  private:
   friend class PolymorphicInliner;
@@ skipping 12 matching lines @@
     // 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()) &&
           !Contains(call_instructions_printed, info.call_instr->GetDeoptId())) {
         for (int t = 0; t < depth; t++) {
-          ISL_Print("  ");
+          THR_Print("  ");
         }
-        ISL_Print("%" Pd " %s\n",
+        THR_Print("%" Pd " %s\n",
             info.call_instr->GetDeoptId(),
             info.inlined->ToQualifiedCString());
         PrintInlinedInfoFor(*info.inlined, depth + 1);
         call_instructions_printed.Add(info.call_instr->GetDeoptId());
       }
     }
     call_instructions_printed.Clear();
     // 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()) &&
           !Contains(call_instructions_printed, info.call_instr->GetDeoptId())) {
         for (int t = 0; t < depth; t++) {
-          ISL_Print("  ");
+          THR_Print("  ");
         }
-        ISL_Print("NO %" Pd " %s - %s\n",
+        THR_Print("NO %" Pd " %s - %s\n",
             info.call_instr->GetDeoptId(),
             info.inlined->ToQualifiedCString(),
             info.bailout_reason);
         call_instructions_printed.Add(info.call_instr->GetDeoptId());
       }
     }
   }
 
   void InlineCall(InlinedCallData* call_data) {
     CSTAT_TIMER_SCOPE(Thread::Current(), graphinliner_subst_timer);
@@ skipping 77 matching lines @@
     parsed_function->AllocateVariables();
     return parsed_function;
   }
 
   // Include special handling for List. factory: inlining it is not helpful
   // if the incoming argument is a non-constant value.
   // TODO(srdjan): Fix inlining of List. factory.
   void InlineStaticCalls() {
     const GrowableArray<CallSites::StaticCallInfo>& call_info =
         inlining_call_sites_->static_calls();
-    TRACE_INLINING(ISL_Print("  Static Calls (%" Pd ")\n", call_info.length()));
+    TRACE_INLINING(THR_Print("  Static Calls (%" Pd ")\n", call_info.length()));
     for (intptr_t call_idx = 0; call_idx < call_info.length(); ++call_idx) {
       StaticCallInstr* call = call_info[call_idx].call;
       if (call->function().name() == Symbols::ListFactory().raw()) {
         // Inline only if no arguments or a constant was passed.
         ASSERT(call->function().NumImplicitParameters() == 1);
         ASSERT(call->ArgumentCount() <= 2);
         // Arg 0: Instantiator type arguments.
         // Arg 1: Length (optional).
         if ((call->ArgumentCount() == 2) &&
             (!call->PushArgumentAt(1)->value()->BindsToConstant())) {
           // Do not inline since a non-constant argument was passed.
           continue;
         }
       }
       const Function& target = call->function();
       if (!inliner_->AlwaysInline(target) &&
           (call_info[call_idx].ratio * 100) < FLAG_inlining_hotness) {
-        TRACE_INLINING(ISL_Print(
+        TRACE_INLINING(THR_Print(
             "  => %s (deopt count %d)\n     Bailout: cold %f\n",
             target.ToCString(),
             target.deoptimization_counter(),
             call_info[call_idx].ratio));
         PRINT_INLINING_TREE("Too cold",
             &call_info[call_idx].caller(), &call->function(), call);
         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(),
           call_info[call_idx].caller_graph->inlining_id());
       if (TryInlining(call->function(), call->argument_names(), &call_data)) {
         InlineCall(&call_data);
       }
     }
   }
 
   void InlineClosureCalls() {
     const GrowableArray<CallSites::ClosureCallInfo>& call_info =
         inlining_call_sites_->closure_calls();
-    TRACE_INLINING(ISL_Print("  Closure Calls (%" Pd ")\n",
+    TRACE_INLINING(THR_Print("  Closure Calls (%" Pd ")\n",
         call_info.length()));
     for (intptr_t call_idx = 0; call_idx < call_info.length(); ++call_idx) {
       ClosureCallInstr* call = call_info[call_idx].call;
       // Find the closure of the callee.
       ASSERT(call->ArgumentCount() > 0);
       Function& target = Function::ZoneHandle();
       AllocateObjectInstr* alloc =
           call->ArgumentAt(0)->OriginalDefinition()->AsAllocateObject();
       if ((alloc != NULL) && !alloc->closure_function().IsNull()) {
         target ^= alloc->closure_function().raw();
         ASSERT(target.signature_class() == alloc->cls().raw());
       }
       ConstantInstr* constant =
           call->ArgumentAt(0)->OriginalDefinition()->AsConstant();
       if ((constant != NULL) &&
           constant->value().IsInstance() &&
           Instance::Cast(constant->value()).IsClosure()) {
         target ^= Closure::function(Instance::Cast(constant->value()));
       }
 
       if (target.IsNull()) {
-        TRACE_INLINING(ISL_Print("     Bailout: non-closure operator\n"));
+        TRACE_INLINING(THR_Print("     Bailout: non-closure operator\n"));
         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(),
           call_info[call_idx].caller_graph->inlining_id());
       if (TryInlining(target,
                       call->argument_names(),
                       &call_data)) {
         InlineCall(&call_data);
       }
     }
   }
 
   void InlineInstanceCalls() {
     const GrowableArray<CallSites::InstanceCallInfo>& call_info =
         inlining_call_sites_->instance_calls();
-    TRACE_INLINING(ISL_Print("  Polymorphic Instance Calls (%" Pd ")\n",
+    TRACE_INLINING(THR_Print("  Polymorphic Instance Calls (%" Pd ")\n",
                              call_info.length()));
     for (intptr_t call_idx = 0; call_idx < call_info.length(); ++call_idx) {
       PolymorphicInstanceCallInstr* call = call_info[call_idx].call;
       if (call->with_checks()) {
         // PolymorphicInliner introduces deoptimization paths.
         if (!FLAG_polymorphic_with_deopt) return;
         const Function& cl = call_info[call_idx].caller();
         intptr_t caller_inlining_id =
             call_info[call_idx].caller_graph->inlining_id();
         PolymorphicInliner inliner(this, call, cl, caller_inlining_id);
         inliner.Inline();
         continue;
       }
 
       const ICData& ic_data = call->ic_data();
       const Function& target = Function::ZoneHandle(ic_data.GetTargetAt(0));
       if (!inliner_->AlwaysInline(target) &&
           (call_info[call_idx].ratio * 100) < FLAG_inlining_hotness) {
-        TRACE_INLINING(ISL_Print(
+        TRACE_INLINING(THR_Print(
             "  => %s (deopt count %d)\n     Bailout: cold %f\n",
             target.ToCString(),
             target.deoptimization_counter(),
             call_info[call_idx].ratio));
         PRINT_INLINING_TREE("Too cold",
             &call_info[call_idx].caller(), &target, call);
         continue;
       }
       GrowableArray<Value*> arguments(call->ArgumentCount());
       for (int arg_i = 0; arg_i < call->ArgumentCount(); ++arg_i) {
@@ skipping 660 matching lines @@
          (function.name() == Symbols::AssignIndexToken().raw()) ||
          (function.name() == Symbols::Plus().raw()) ||
          (function.name() == Symbols::Minus().raw());
 }
 
 
 bool FlowGraphInliner::AlwaysInline(const Function& function) {
   const char* kAlwaysInlineAnnotation = "AlwaysInline";
   if (FLAG_enable_inlining_annotations &&
       HasAnnotation(function, kAlwaysInlineAnnotation)) {
-    TRACE_INLINING(ISL_Print("AlwaysInline annotation for %s\n",
+    TRACE_INLINING(THR_Print("AlwaysInline annotation for %s\n",
                              function.ToCString()));
     return true;
   }
 
   if (function.IsImplicitGetterFunction() || function.IsGetterFunction() ||
       function.IsImplicitSetterFunction() || function.IsSetterFunction() ||
       IsInlineableOperator(function)) {
     const intptr_t count = function.optimized_instruction_count();
     if ((count != 0) && (count < FLAG_inline_getters_setters_smaller_than)) {
       return true;
     }
   }
   return MethodRecognizer::AlwaysInline(function);
 }
 
 
 void FlowGraphInliner::Inline() {
   // Collect graph info and store it on the function.
   // We might later use it for an early bailout from the inlining.
   CollectGraphInfo(flow_graph_);
 
   const Function& top = flow_graph_->function();
   if ((FLAG_inlining_filter != NULL) &&
       (strstr(top.ToFullyQualifiedCString(), FLAG_inlining_filter) == NULL)) {
     return;
   }
 
-  TRACE_INLINING(ISL_Print("Inlining calls in %s\n", top.ToCString()));
+  TRACE_INLINING(THR_Print("Inlining calls in %s\n", top.ToCString()));
 
   if (trace_inlining() &&
       (FLAG_print_flow_graph || FLAG_print_flow_graph_optimized)) {
-    ISL_Print("Before Inlining of %s\n", flow_graph_->
+    THR_Print("Before Inlining of %s\n", flow_graph_->
               function().ToFullyQualifiedCString());
     FlowGraphPrinter printer(*flow_graph_);
     printer.PrintBlocks();
   }
 
   CallSiteInliner inliner(this);
   inliner.InlineCalls();
   if (FLAG_print_inlining_tree) {
     inliner.PrintInlinedInfo(top);
   }
 
   if (inliner.inlined()) {
     flow_graph_->DiscoverBlocks();
     if (trace_inlining()) {
-      ISL_Print("Inlining growth factor: %f\n", inliner.GrowthFactor());
+      THR_Print("Inlining growth factor: %f\n", inliner.GrowthFactor());
       if (FLAG_print_flow_graph || FLAG_print_flow_graph_optimized) {
-        ISL_Print("After Inlining of %s\n", flow_graph_->
+        THR_Print("After Inlining of %s\n", flow_graph_->
                   function().ToFullyQualifiedCString());
         FlowGraphPrinter printer(*flow_graph_);
         printer.PrintBlocks();
       }
     }
   }
 }
 
 
 intptr_t FlowGraphInliner::NextInlineId(const Function& function,
                                         intptr_t parent_id) {
   const intptr_t id = inline_id_to_function_->length();
   inline_id_to_function_->Add(&function);
   caller_inline_id_->Add(parent_id);
   return id;
 }
 
 
 }  // namespace dart