Split flag --trace-deopt into --trace-deoptimization and --trace-deoptimization-verbose. Print sour…

runtime/vm/code_generator.cc

 // Copyright (c) 2012, 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/code_generator.h"
 
 #include "vm/assembler_macros.h"
 #include "vm/ast.h"
 #include "vm/code_patcher.h"
 #include "vm/compiler.h"
@@ skipping 12 matching lines @@
 #include "vm/stack_frame.h"
 #include "vm/symbols.h"
 #include "vm/verifier.h"
 
 namespace dart {
 
 DEFINE_FLAG(bool, deoptimize_alot, false,
     "Deoptimizes all live frames when we are about to return to Dart code from"
     " native entries.");
 DEFINE_FLAG(bool, inline_cache, true, "Enable inline caches");
-DEFINE_FLAG(bool, trace_deopt, false, "Trace deoptimization");
+DEFINE_FLAG(bool, trace_deoptimization, false, "Trace deoptimization");
+DEFINE_FLAG(bool, trace_deoptimization_verbose, false,
+    "Trace deoptimization verbose");
 DEFINE_FLAG(bool, trace_ic, false, "Trace IC handling");
 DEFINE_FLAG(bool, trace_ic_miss_in_optimized, false,
     "Trace IC miss in optimized code");
 DEFINE_FLAG(bool, trace_patching, false, "Trace patching of code.");
 DEFINE_FLAG(bool, trace_runtime_calls, false, "Trace runtime calls");
 DEFINE_FLAG(int, optimization_counter_threshold, 2000,
     "Function's usage-counter value before it is optimized, -1 means never");
 DECLARE_FLAG(bool, enable_type_checks);
 DECLARE_FLAG(bool, trace_type_checks);
 DECLARE_FLAG(bool, report_usage_count);
@@ skipping 1500 matching lines @@
   // Include the return address of optimized code.
   intptr_t* start = reinterpret_cast<intptr_t*>(frame.sp() - kWordSize);
   for (intptr_t i = 0; i < frame_copy_size; i++) {
     frame_copy[i] = *(start + i);
   }
   Isolate::Current()->SetDeoptFrameCopy(frame_copy, frame_copy_size);
 }
 
 
 // Copies saved registers and caller's frame into temporary buffers.
-// Returns the stack size of unoptimzied frame.
+// Returns the stack size of unoptimized frame.
 DEFINE_LEAF_RUNTIME_ENTRY(intptr_t, DeoptimizeCopyFrame,
                           uword saved_registers_address) {
   Isolate* isolate = Isolate::Current();
   Zone zone(isolate);
   HANDLESCOPE(isolate);
 
   // All registers have been saved below last-fp.
   const uword last_fp = saved_registers_address +
       kNumberOfCpuRegisters * kWordSize + kNumberOfXmmRegisters * kDoubleSize;
   CopySavedRegisters(saved_registers_address);
 
   // Get optimized code and frame that need to be deoptimized.
   DartFrameIterator iterator(last_fp);
   StackFrame* caller_frame = iterator.NextFrame();
   ASSERT(caller_frame != NULL);
   const Code& optimized_code = Code::Handle(caller_frame->LookupDartCode());
   ASSERT(optimized_code.is_optimized());
 
 
   DeoptInfo& deopt_info = DeoptInfo::Handle();
   DeoptReasonId deopt_reason = kDeoptUnknown;
   GetDeoptInfoAtPc(optimized_code, caller_frame->pc(), &deopt_info,
                    &deopt_reason);
   ASSERT(!deopt_info.IsNull());
 
   CopyFrame(optimized_code, *caller_frame);
-  if (FLAG_trace_deopt) {
+  if (FLAG_trace_deoptimization) {
     OS::Print("Deoptimizing (reason %d '%s') at pc %#"Px" '%s'\n",
         deopt_reason,
         DeoptReasonToText(deopt_reason),
         caller_frame->pc(),
         Function::Handle(optimized_code.function()).ToFullyQualifiedCString());
   }
 
   // Compute the stack size of the unoptimized frame.  For functions with
   // optional arguments the deoptimization info does not describe the
   // incoming arguments.
@@ skipping 28 matching lines @@
       + (caller_frame.fp() - caller_frame.sp()) / kWordSize
       + 3  // caller-fp, pc, pc-marker.
       + num_args;
   DeoptimizationContext deopt_context(start,
                                       to_frame_size,
                                       Array::Handle(code.object_table()),
                                       num_args);
   for (intptr_t to_index = len - 1; to_index >= 0; to_index--) {
     deopt_instructions[to_index]->Execute(&deopt_context, to_index);
   }
-  if (FLAG_trace_deopt) {
+  if (FLAG_trace_deoptimization_verbose) {
     for (intptr_t i = 0; i < len; i++) {
       OS::Print("*%"Pd". [%p] %#014"Px" [%s]\n",
           i,
           &start[i],
           start[i],
           deopt_instructions[i]->ToCString());
     }
   }
   return deopt_context.GetCallerFp();
 }
@@ skipping 42 matching lines @@
   function.set_deoptimization_counter(function.deoptimization_counter() + 1);
 
   if (function.HasOptimizedCode()) {
     function.SwitchToUnoptimizedCode();
   }
   return caller_fp;
 }
 END_LEAF_RUNTIME_ENTRY
 
 
+// This is the last step in the deoptimization, GC can occur.
 DEFINE_RUNTIME_ENTRY(DeoptimizeMaterializeDoubles, 0) {
   DeferredDouble* deferred_double = Isolate::Current()->DetachDeferredDoubles();
 
   while (deferred_double != NULL) {
     DeferredDouble* current = deferred_double;
     deferred_double = deferred_double->next();
 
     RawDouble** slot = current->slot();
     *slot = Double::New(current->value());
 
-    if (FLAG_trace_deopt) {
+    if (FLAG_trace_deoptimization_verbose) {
       OS::Print("materializing double at %"Px": %g\n",
                 reinterpret_cast<uword>(current->slot()),
                 current->value());
     }
 
     delete current;
   }
 
   DeferredMint* deferred_mint = Isolate::Current()->DetachDeferredMints();
 
   while (deferred_mint != NULL) {
     DeferredMint* current = deferred_mint;
     deferred_mint = deferred_mint->next();
 
     RawMint** slot = current->slot();
     ASSERT(!Smi::IsValid64(current->value()));
     *slot = Mint::New(current->value());
 
-    if (FLAG_trace_deopt) {
+    if (FLAG_trace_deoptimization_verbose) {
       OS::Print("materializing mint at %"Px": %"Pd64"\n",
                 reinterpret_cast<uword>(current->slot()),
                 current->value());
     }
 
     delete current;
   }
+  // Since this is the only step where GC can occur during deoptimization,
+  // use it to report the source line where deoptimization occured.
+  if (FLAG_trace_deoptimization) {
+    DartFrameIterator iterator;
+    StackFrame* top_frame = iterator.NextFrame();
+    ASSERT(top_frame != NULL);
+    const Code& code = Code::Handle(top_frame->LookupDartCode());
+    const Function& top_function = Function::Handle(code.function());
+    const Script& script = Script::Handle(top_function.script());
+    const intptr_t token_pos = code.GetTokenIndexOfPC(top_frame->pc());
+    intptr_t line, column;
+    script.GetTokenLocation(token_pos, &line, &column);
+    String& line_string = String::Handle(script.GetLine(line));
+    OS::Print("  Function: %s\n", top_function.ToFullyQualifiedCString());
+    OS::Print("  Line %"Pd": '%s'\n", line, line_string.ToCString());
+  }
 }
 
 
 }  // namespace dart