Improve trace_opt output to help find compilation problems

R=jkummerow@chromium.org

Review URL: https://codereview.chromium.org/14978003

git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@14636 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/arm/deoptimizer-arm.cc

@@ -55,7 +55,7 @@ void Deoptimizer::DeoptimizeFunctionWithPreparedFunctionList(
 
   // The optimized code is going to be patched, so we cannot use it
   // any more.  Play safe and reset the whole cache.
-  function->shared()->ClearOptimizedCodeMap();
+  function->shared()->ClearOptimizedCodeMap("deoptimized function");
 
   // Get the optimized code.
   Code* code = function->code();

src/compiler.cc

@@ -216,9 +216,8 @@ void OptimizingCompiler::RecordOptimizationStats() {
   double ms_optimize = static_cast<double>(time_taken_to_optimize_) / 1000;
   double ms_codegen = static_cast<double>(time_taken_to_codegen_) / 1000;
   if (FLAG_trace_opt) {
-    PrintF("[optimizing: ");
-    function->PrintName();
-    PrintF(" / %" V8PRIxPTR, reinterpret_cast<intptr_t>(*function));
+    PrintF("[optimizing ");
+    function->ShortPrint();
     PrintF(" - took %0.3f, %0.3f, %0.3f ms]\n", ms_creategraph, ms_optimize,
            ms_codegen);
   }
@@ -315,15 +314,9 @@ OptimizingCompiler::Status OptimizingCompiler::CreateGraph() {
   }
 
   // Take --hydrogen-filter into account.
-  Handle<String> name = info()->function()->debug_name();
-  if (*FLAG_hydrogen_filter != '\0') {
-    Vector<const char> filter = CStrVector(FLAG_hydrogen_filter);
-    if ((filter[0] == '-'
-         && name->IsUtf8EqualTo(filter.SubVector(1, filter.length())))
-        || (filter[0] != '-' && !name->IsUtf8EqualTo(filter))) {
+  if (!info()->closure()->PassesHydrogenFilter()) {
       info()->SetCode(code);
       return SetLastStatus(BAILED_OUT);
-    }
   }
 
   // Recompile the unoptimized version of the code if the current version
@@ -360,6 +353,7 @@ OptimizingCompiler::Status OptimizingCompiler::CreateGraph() {
   ASSERT(info()->shared_info()->has_deoptimization_support());
 
   if (FLAG_trace_hydrogen) {
+    Handle<String> name = info()->function()->debug_name();
     PrintF("-----------------------------------------------------------\n");
     PrintF("Compiling method %s using hydrogen\n", *name->ToCString());
     isolate()->GetHTracer()->TraceCompilation(info());
@@ -843,9 +837,9 @@ static bool InstallCodeFromOptimizedCodeMap(CompilationInfo* info) {
     int index = shared->SearchOptimizedCodeMap(*native_context);
     if (index > 0) {
       if (FLAG_trace_opt) {
-        PrintF("[found optimized code for: ");
-        function->PrintName();
-        PrintF(" / %" V8PRIxPTR "]\n", reinterpret_cast<intptr_t>(*function));
+        PrintF("[found optimized code for ");
+        function->ShortPrint();
+        PrintF("]\n");
       }
       // Caching of optimized code enabled and optimized code found.
       shared->InstallFromOptimizedCodeMap(*function, index);

src/heap.cc

@@ -3291,7 +3291,7 @@ MaybeObject* Heap::AllocateSharedFunctionInfo(Object* name) {
   share->set_name(name);
   Code* illegal = isolate_->builtins()->builtin(Builtins::kIllegal);
   share->set_code(illegal);
-  share->ClearOptimizedCodeMap();
+  share->set_optimized_code_map(Smi::FromInt(0));
   share->set_scope_info(ScopeInfo::Empty(isolate_));
   Code* construct_stub =
       isolate_->builtins()->builtin(Builtins::kJSConstructStubGeneric);

src/ia32/deoptimizer-ia32.cc

@@ -125,7 +125,7 @@ void Deoptimizer::DeoptimizeFunctionWithPreparedFunctionList(
 
   // The optimized code is going to be patched, so we cannot use it
   // any more.  Play safe and reset the whole cache.
-  function->shared()->ClearOptimizedCodeMap();
+  function->shared()->ClearOptimizedCodeMap("deoptimized function");
 
   // Get the optimized code.
   Code* code = function->code();

src/mips/deoptimizer-mips.cc

@@ -53,7 +53,7 @@ void Deoptimizer::DeoptimizeFunctionWithPreparedFunctionList(
 
   // The optimized code is going to be patched, so we cannot use it
   // any more.  Play safe and reset the whole cache.
-  function->shared()->ClearOptimizedCodeMap();
+  function->shared()->ClearOptimizedCodeMap("deoptimized function");
 
   // Get the optimized code.
   Code* code = function->code();

src/objects-inl.h

@@ -4680,11 +4680,6 @@ void SharedFunctionInfo::BeforeVisitingPointers() {
 }
 
 
-void SharedFunctionInfo::ClearOptimizedCodeMap() {
-  set_optimized_code_map(Smi::FromInt(0));
-}
-
-
 ACCESSORS(CodeCache, default_cache, FixedArray, kDefaultCacheOffset)
 ACCESSORS(CodeCache, normal_type_cache, Object, kNormalTypeCacheOffset)
 

src/objects-visiting-inl.h

@@ -316,7 +316,7 @@ void StaticMarkingVisitor<StaticVisitor>::VisitSharedFunctionInfo(
     // TODO(mstarzinger): We may experiment with rebuilding it or with
     // retaining entries which should survive as we iterate through
     // optimized functions anyway.
-    shared->ClearOptimizedCodeMap();
+    shared->ClearOptimizedCodeMap("during full gc");
   }
   MarkCompactCollector* collector = heap->mark_compact_collector();
   if (collector->is_code_flushing_enabled()) {

src/objects.cc

@@ -1291,20 +1291,23 @@ void JSObject::JSObjectShortPrint(StringStream* accumulator) {
       break;
     }
     case JS_FUNCTION_TYPE: {
-      Object* fun_name = JSFunction::cast(this)->shared()->name();
+      JSFunction* function = JSFunction::cast(this);
+      Object* fun_name = function->shared()->DebugName();
       bool printed = false;
       if (fun_name->IsString()) {
         String* str = String::cast(fun_name);
         if (str->length() > 0) {
           accumulator->Add("<JS Function ");
           accumulator->Put(str);
-          accumulator->Put('>');
           printed = true;
         }
       }
       if (!printed) {
-        accumulator->Add("<JS Function>");
+        accumulator->Add("<JS Function");
       }
+      accumulator->Add(" (SharedFunctionInfo %p)",
+                       reinterpret_cast<intptr_t>(function->shared()));
+      accumulator->Put('>');
       break;
     }
     case JS_GENERATOR_OBJECT_TYPE: {
@@ -1341,6 +1344,9 @@ void JSObject::JSObjectShortPrint(StringStream* accumulator) {
                        global_object ? "Global Object: " : "",
                        vowel ? "n" : "");
                 accumulator->Put(str);
+                accumulator->Add(" with %smap 0x%p",
+                    map_of_this->is_deprecated() ? "deprecated " : "",
+                    map_of_this);
                 printed = true;
               }
             }
@@ -1456,9 +1462,17 @@ void HeapObject::HeapObjectShortPrint(StringStream* accumulator) {
       accumulator->Add("<ExternalDoubleArray[%u]>",
                        ExternalDoubleArray::cast(this)->length());
       break;
-    case SHARED_FUNCTION_INFO_TYPE:
-      accumulator->Add("<SharedFunctionInfo>");
+    case SHARED_FUNCTION_INFO_TYPE: {
+      SharedFunctionInfo* shared = SharedFunctionInfo::cast(this);
+      SmartArrayPointer<char> debug_name =
+          shared->DebugName()->ToCString();
+      if (debug_name[0] != 0) {
+        accumulator->Add("<SharedFunctionInfo %s>", *debug_name);
+      } else {
+        accumulator->Add("<SharedFunctionInfo>");
+      }
       break;
+    }
     case JS_MESSAGE_OBJECT_TYPE:
       accumulator->Add("<JSMessageObject>");
       break;
@@ -8371,12 +8385,13 @@ bool String::MarkAsUndetectable() {
 }
 
 
-bool String::IsUtf8EqualTo(Vector<const char> str) {
+bool String::IsUtf8EqualTo(Vector<const char> str, bool allow_prefix_match) {
   int slen = length();
   // Can't check exact length equality, but we can check bounds.
   int str_len = str.length();
-  if (str_len < slen ||
-      str_len > slen*static_cast<int>(unibrow::Utf8::kMaxEncodedSize)) {
+  if (!allow_prefix_match &&
+      (str_len < slen ||
+          str_len > slen*static_cast<int>(unibrow::Utf8::kMaxEncodedSize))) {
     return false;
   }
   int i;
@@ -8396,7 +8411,7 @@ bool String::IsUtf8EqualTo(Vector<const char> str) {
     utf8_data += cursor;
     remaining_in_str -= cursor;
   }
-  return i == slen && remaining_in_str == 0;
+  return (allow_prefix_match || i == slen) && remaining_in_str == 0;
 }
 
 
@@ -9016,6 +9031,18 @@ void SharedFunctionInfo::InstallFromOptimizedCodeMap(JSFunction* function,
 }
 
 
+void SharedFunctionInfo::ClearOptimizedCodeMap(const char* reason) {
+  if (!optimized_code_map()->IsSmi()) {
+    if (FLAG_trace_opt) {
+      PrintF("[clearing optimizing code map (%s) for ", reason);
+      ShortPrint();
+      PrintF("]\n");
+    }
+    set_optimized_code_map(Smi::FromInt(0));
+  }
+}
+
+
 bool JSFunction::CompileLazy(Handle<JSFunction> function,
                              ClearExceptionFlag flag) {
   bool result = true;
@@ -9229,6 +9256,26 @@ Context* JSFunction::NativeContextFromLiterals(FixedArray* literals) {
 }
 
 
+bool JSFunction::PassesHydrogenFilter() {
+  String* name = shared()->DebugName();
+  if (*FLAG_hydrogen_filter != '\0') {
+    Vector<const char> filter = CStrVector(FLAG_hydrogen_filter);
+    if (filter[0] != '-' && name->IsUtf8EqualTo(filter)) return true;
+    if (filter[0] == '-' &&
+        !name->IsUtf8EqualTo(filter.SubVector(1, filter.length()))) {
+      return true;
+    }
+    if (filter[filter.length() - 1] == '*' &&
+        name->IsUtf8EqualTo(filter.SubVector(0, filter.length() - 1), true)) {
+      return true;
+    }
+    return false;
+  }
+
+  return true;
+}
+
+
 MaybeObject* Oddball::Initialize(const char* to_string,
                                  Object* to_number,
                                  byte kind) {
@@ -9483,8 +9530,9 @@ void SharedFunctionInfo::DisableOptimization(const char* reason) {
     code()->set_optimizable(false);
   }
   if (FLAG_trace_opt) {
-    PrintF("[disabled optimization for %s, reason: %s]\n",
-           *DebugName()->ToCString(), reason);
+    PrintF("[disabled optimization for ");
+    ShortPrint();
+    PrintF(", reason: %s]\n", reason);
   }
 }
 
@@ -9639,6 +9687,11 @@ int SharedFunctionInfo::SearchOptimizedCodeMap(Context* native_context) {
         return i + 1;
       }
     }
+    if (FLAG_trace_opt) {
+      PrintF("[didn't find optimized code in optimized code map for ");
+      ShortPrint();
+      PrintF("]\n");
+    }
   }
   return -1;
 }

src/objects.h

@@ -5820,7 +5820,7 @@ class SharedFunctionInfo: public HeapObject {
   void InstallFromOptimizedCodeMap(JSFunction* function, int index);
 
   // Clear optimized code map.
-  inline void ClearOptimizedCodeMap();
+  void ClearOptimizedCodeMap(const char* reason);
 
   // Add a new entry to the optimized code map.
   static void AddToOptimizedCodeMap(Handle<SharedFunctionInfo> shared,
@@ -6678,6 +6678,8 @@ class JSFunction: public JSObject {
   }
 #endif
 
+  bool PassesHydrogenFilter();
+
   // Layout descriptors. The last property (from kNonWeakFieldsEndOffset to
   // kSize) is weak and has special handling during garbage collection.
   static const int kCodeEntryOffset = JSObject::kHeaderSize;
@@ -7810,7 +7812,7 @@ class String: public Name {
 
   // String equality operations.
   inline bool Equals(String* other);
-  bool IsUtf8EqualTo(Vector<const char> str);
+  bool IsUtf8EqualTo(Vector<const char> str, bool allow_prefix_match = false);
   bool IsOneByteEqualTo(Vector<const uint8_t> str);
   bool IsTwoByteEqualTo(Vector<const uc16> str);
 

src/runtime-profiler.cc

@@ -122,10 +122,9 @@ static void GetICCounts(JSFunction* function,
 void RuntimeProfiler::Optimize(JSFunction* function, const char* reason) {
   ASSERT(function->IsOptimizable());
 
-  if (FLAG_trace_opt) {
+  if (FLAG_trace_opt && function->PassesHydrogenFilter()) {
     PrintF("[marking ");
-    function->PrintName();
-    PrintF(" 0x%" V8PRIxPTR, reinterpret_cast<intptr_t>(function->address()));
+    function->ShortPrint();
     PrintF(" for recompilation, reason: %s", reason);
     if (FLAG_type_info_threshold > 0) {
       int typeinfo, total, percentage;

src/runtime.cc

@@ -8011,7 +8011,7 @@ RUNTIME_FUNCTION(MaybeObject*, Runtime_NotifyDeoptimized) {
     Deoptimizer::DeoptimizeFunction(*function);
   }
   // Flush optimized code cache for this function.
-  function->shared()->ClearOptimizedCodeMap();
+  function->shared()->ClearOptimizedCodeMap("notify deoptimized");
 
   return isolate->heap()->undefined_value();
 }

src/x64/deoptimizer-x64.cc

@@ -57,7 +57,7 @@ void Deoptimizer::DeoptimizeFunctionWithPreparedFunctionList(
 
   // The optimized code is going to be patched, so we cannot use it
   // any more.  Play safe and reset the whole cache.
-  function->shared()->ClearOptimizedCodeMap();
+  function->shared()->ClearOptimizedCodeMap("deoptimized function");
 
   // Get the optimized code.
   Code* code = function->code();