From cf1b80703f3bba5eaa0b201faafa4682ae312d32 Mon Sep 17 00:00:00 2001 From: "danno@chromium.org" Date: Mon, 13 May 2013 11:10:31 +0000 Subject: [PATCH] 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 | 2 +- src/compiler.cc | 20 +++++------- src/heap.cc | 2 +- src/ia32/deoptimizer-ia32.cc | 2 +- src/mips/deoptimizer-mips.cc | 2 +- src/objects-inl.h | 5 --- src/objects-visiting-inl.h | 2 +- src/objects.cc | 75 +++++++++++++++++++++++++++++++++++++------- src/objects.h | 6 ++-- src/runtime-profiler.cc | 5 ++- src/runtime.cc | 2 +- src/x64/deoptimizer-x64.cc | 2 +- 12 files changed, 84 insertions(+), 41 deletions(-) diff --git a/src/arm/deoptimizer-arm.cc b/src/arm/deoptimizer-arm.cc index 001d3c8..41379d5 100644 --- a/src/arm/deoptimizer-arm.cc +++ b/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(); diff --git a/src/compiler.cc b/src/compiler.cc index b7ff92a..76fb726 100644 --- a/src/compiler.cc +++ b/src/compiler.cc @@ -216,9 +216,8 @@ void OptimizingCompiler::RecordOptimizationStats() { double ms_optimize = static_cast(time_taken_to_optimize_) / 1000; double ms_codegen = static_cast(time_taken_to_codegen_) / 1000; if (FLAG_trace_opt) { - PrintF("[optimizing: "); - function->PrintName(); - PrintF(" / %" V8PRIxPTR, reinterpret_cast(*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 name = info()->function()->debug_name(); - if (*FLAG_hydrogen_filter != '\0') { - Vector 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 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(*function)); + PrintF("[found optimized code for "); + function->ShortPrint(); + PrintF("]\n"); } // Caching of optimized code enabled and optimized code found. shared->InstallFromOptimizedCodeMap(*function, index); diff --git a/src/heap.cc b/src/heap.cc index bf2712d..6a6afc0 100644 --- a/src/heap.cc +++ b/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); diff --git a/src/ia32/deoptimizer-ia32.cc b/src/ia32/deoptimizer-ia32.cc index f8aff48..6718b8f 100644 --- a/src/ia32/deoptimizer-ia32.cc +++ b/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(); diff --git a/src/mips/deoptimizer-mips.cc b/src/mips/deoptimizer-mips.cc index ecf4087..7cc5444 100644 --- a/src/mips/deoptimizer-mips.cc +++ b/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(); diff --git a/src/objects-inl.h b/src/objects-inl.h index 5b45cba..7628cf2 100644 --- a/src/objects-inl.h +++ b/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) diff --git a/src/objects-visiting-inl.h b/src/objects-visiting-inl.h index 9b39bef..4c9a4bd 100644 --- a/src/objects-visiting-inl.h +++ b/src/objects-visiting-inl.h @@ -316,7 +316,7 @@ void StaticMarkingVisitor::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()) { diff --git a/src/objects.cc b/src/objects.cc index 6ea982c..dfcb29b 100644 --- a/src/objects.cc +++ b/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("Put(str); - accumulator->Put('>'); printed = true; } } if (!printed) { - accumulator->Add(""); + accumulator->Add("Add(" (SharedFunctionInfo %p)", + reinterpret_cast(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::cast(this)->length()); break; - case SHARED_FUNCTION_INFO_TYPE: - accumulator->Add(""); + case SHARED_FUNCTION_INFO_TYPE: { + SharedFunctionInfo* shared = SharedFunctionInfo::cast(this); + SmartArrayPointer debug_name = + shared->DebugName()->ToCString(); + if (debug_name[0] != 0) { + accumulator->Add("", *debug_name); + } else { + accumulator->Add(""); + } break; + } case JS_MESSAGE_OBJECT_TYPE: accumulator->Add(""); break; @@ -8371,12 +8385,13 @@ bool String::MarkAsUndetectable() { } -bool String::IsUtf8EqualTo(Vector str) { +bool String::IsUtf8EqualTo(Vector 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(unibrow::Utf8::kMaxEncodedSize)) { + if (!allow_prefix_match && + (str_len < slen || + str_len > slen*static_cast(unibrow::Utf8::kMaxEncodedSize))) { return false; } int i; @@ -8396,7 +8411,7 @@ bool String::IsUtf8EqualTo(Vector 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 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 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; } diff --git a/src/objects.h b/src/objects.h index b671558..eebf3c1 100644 --- a/src/objects.h +++ b/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 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 str); + bool IsUtf8EqualTo(Vector str, bool allow_prefix_match = false); bool IsOneByteEqualTo(Vector str); bool IsTwoByteEqualTo(Vector str); diff --git a/src/runtime-profiler.cc b/src/runtime-profiler.cc index 95e86b1..c4b79b1 100644 --- a/src/runtime-profiler.cc +++ b/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(function->address())); + function->ShortPrint(); PrintF(" for recompilation, reason: %s", reason); if (FLAG_type_info_threshold > 0) { int typeinfo, total, percentage; diff --git a/src/runtime.cc b/src/runtime.cc index 774e961..cb22670 100644 --- a/src/runtime.cc +++ b/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(); } diff --git a/src/x64/deoptimizer-x64.cc b/src/x64/deoptimizer-x64.cc index bec158b..36280ec 100644 --- a/src/x64/deoptimizer-x64.cc +++ b/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(); -- 2.7.4