From: mikhail.naganov@gmail.com Date: Thu, 15 Oct 2009 07:50:23 +0000 (+0000) Subject: Add initial semi-working producers profile. X-Git-Tag: upstream/4.7.83~23144 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=efb8cee3244a7ed82085905ad852174f1cbfe992;p=platform%2Fupstream%2Fv8.git Add initial semi-working producers profile. Turned on with '--log-producers' flag, also needs '--noinline-new' (this is temporarily), '--log-code', '--log-gc'. Not all allocations are traced (I'm investigating.) Stacks are stored using weak handles. Thus, when an object is collected, its allocation stack is deleted. Review URL: http://codereview.chromium.org/267077 git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@3069 ce2b1a6d-e550-0410-aec6-3dcde31c8c00 --- diff --git a/src/flag-definitions.h b/src/flag-definitions.h index 8f2008341..2a964abd0 100644 --- a/src/flag-definitions.h +++ b/src/flag-definitions.h @@ -350,6 +350,7 @@ DEFINE_bool(log_gc, false, DEFINE_bool(log_handles, false, "Log global handle events.") DEFINE_bool(log_state_changes, false, "Log state changes.") DEFINE_bool(log_suspect, false, "Log suspect operations.") +DEFINE_bool(log_producers, false, "Log stack traces of JS objects allocations.") DEFINE_bool(compress_log, false, "Compress log to save space (makes log less human-readable).") DEFINE_bool(prof, false, diff --git a/src/global-handles.cc b/src/global-handles.cc index e51c4aadf..f4b69fcdd 100644 --- a/src/global-handles.cc +++ b/src/global-handles.cc @@ -264,6 +264,16 @@ void GlobalHandles::IterateWeakRoots(ObjectVisitor* v) { } +void GlobalHandles::IterateWeakRoots(WeakReferenceGuest f, + WeakReferenceCallback callback) { + for (Node* current = head_; current != NULL; current = current->next()) { + if (current->IsWeak() && current->callback() == callback) { + f(current->object_, current->parameter()); + } + } +} + + void GlobalHandles::IdentifyWeakHandles(WeakSlotCallback f) { for (Node* current = head_; current != NULL; current = current->next()) { if (current->state_ == Node::WEAK) { diff --git a/src/global-handles.h b/src/global-handles.h index 9e63ba7a9..feb95bf2a 100644 --- a/src/global-handles.h +++ b/src/global-handles.h @@ -54,6 +54,8 @@ class ObjectGroup : public Malloced { }; +typedef void (*WeakReferenceGuest)(Object* object, void* parameter); + class GlobalHandles : public AllStatic { public: // Creates a new global handle that is alive until Destroy is called. @@ -99,6 +101,10 @@ class GlobalHandles : public AllStatic { // Iterates over all weak roots in heap. static void IterateWeakRoots(ObjectVisitor* v); + // Iterates over weak roots that are bound to a given callback. + static void IterateWeakRoots(WeakReferenceGuest f, + WeakReferenceCallback callback); + // Find all weak handles satisfying the callback predicate, mark // them as pending. static void IdentifyWeakHandles(WeakSlotCallback f); diff --git a/src/heap-profiler.cc b/src/heap-profiler.cc index ecb691987..8f55ce1ce 100644 --- a/src/heap-profiler.cc +++ b/src/heap-profiler.cc @@ -28,6 +28,8 @@ #include "v8.h" #include "heap-profiler.h" +#include "frames-inl.h" +#include "global-handles.h" #include "string-stream.h" namespace v8 { @@ -327,6 +329,11 @@ void ConstructorHeapProfile::PrintStats() { } +static const char* GetConstructorName(const char* name) { + return name[0] != '\0' ? name : "(anonymous)"; +} + + void JSObjectsCluster::Print(StringStream* accumulator) const { ASSERT(!is_null()); if (constructor_ == FromSpecialCase(ROOTS)) { @@ -338,7 +345,7 @@ void JSObjectsCluster::Print(StringStream* accumulator) const { } else { SmartPointer s_name( constructor_->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL)); - accumulator->Add("%s", (*s_name)[0] != '\0' ? *s_name : "(anonymous)"); + accumulator->Add("%s", GetConstructorName(*s_name)); if (instance_ != NULL) { accumulator->Add(":%p", static_cast(instance_)); } @@ -574,6 +581,23 @@ void HeapProfiler::CollectStats(HeapObject* obj, HistogramInfo* info) { } +static void StackWeakReferenceCallback(Persistent object, + void* trace) { + DeleteArray(static_cast(trace)); + object.Dispose(); +} + + +static void PrintProducerStackTrace(Object* obj, void* trace) { + if (!obj->IsJSObject()) return; + String* constructor = JSObject::cast(obj)->constructor_name(); + SmartPointer s_name( + constructor->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL)); + LOG(HeapSampleJSProducerEvent(GetConstructorName(*s_name), + reinterpret_cast(trace))); +} + + void HeapProfiler::WriteSample() { LOG(HeapSampleBeginEvent("Heap", "allocated")); LOG(HeapSampleStats( @@ -616,10 +640,40 @@ void HeapProfiler::WriteSample() { js_cons_profile.PrintStats(); js_retainer_profile.PrintStats(); + GlobalHandles::IterateWeakRoots(PrintProducerStackTrace, + StackWeakReferenceCallback); + LOG(HeapSampleEndEvent("Heap", "allocated")); } +bool ProducerHeapProfile::can_log_ = false; + +void ProducerHeapProfile::Setup() { + can_log_ = true; +} + +void ProducerHeapProfile::RecordJSObjectAllocation(Object* obj) { + if (!can_log_ || !FLAG_log_producers) return; + int framesCount = 0; + for (JavaScriptFrameIterator it; !it.done(); it.Advance()) { + ++framesCount; + } + if (framesCount == 0) return; + ++framesCount; // Reserve place for the terminator item. + Vector
stack(NewArray
(framesCount), framesCount); + int i = 0; + for (JavaScriptFrameIterator it; !it.done(); it.Advance()) { + stack[i++] = it.frame()->pc(); + } + stack[i] = NULL; + Handle handle = GlobalHandles::Create(obj); + GlobalHandles::MakeWeak(handle.location(), + static_cast(stack.start()), + StackWeakReferenceCallback); +} + + #endif // ENABLE_LOGGING_AND_PROFILING diff --git a/src/heap-profiler.h b/src/heap-profiler.h index 7fda883f8..bd875df23 100644 --- a/src/heap-profiler.h +++ b/src/heap-profiler.h @@ -256,6 +256,14 @@ class RetainerHeapProfile BASE_EMBEDDED { }; +class ProducerHeapProfile : public AllStatic { + public: + static void Setup(); + static void RecordJSObjectAllocation(Object* obj); + private: + static bool can_log_; +}; + #endif // ENABLE_LOGGING_AND_PROFILING } } // namespace v8::internal diff --git a/src/heap.cc b/src/heap.cc index 648e48699..817a50f16 100644 --- a/src/heap.cc +++ b/src/heap.cc @@ -2021,6 +2021,7 @@ Object* Heap::Allocate(Map* map, AllocationSpace space) { TargetSpaceId(map->instance_type())); if (result->IsFailure()) return result; HeapObject::cast(result)->set_map(map); + ProducerHeapProfile::RecordJSObjectAllocation(result); return result; } @@ -2342,6 +2343,7 @@ Object* Heap::CopyJSObject(JSObject* source) { JSObject::cast(clone)->set_properties(FixedArray::cast(prop)); } // Return the new clone. + ProducerHeapProfile::RecordJSObjectAllocation(clone); return clone; } @@ -3308,6 +3310,9 @@ bool Heap::Setup(bool create_heap_objects) { LOG(IntEvent("heap-capacity", Capacity())); LOG(IntEvent("heap-available", Available())); + // This should be called only after initial objects have been created. + ProducerHeapProfile::Setup(); + return true; } diff --git a/src/log.cc b/src/log.cc index 1c82f8525..d1d9a31e4 100644 --- a/src/log.cc +++ b/src/log.cc @@ -934,6 +934,21 @@ void Logger::HeapSampleJSRetainersEvent( } +void Logger::HeapSampleJSProducerEvent(const char* constructor, + Address* stack) { +#ifdef ENABLE_LOGGING_AND_PROFILING + if (!Log::IsEnabled() || !FLAG_log_gc) return; + LogMessageBuilder msg; + msg.Append("heap-js-prod-item,%s", constructor); + while (*stack != NULL) { + msg.Append(",0x%" V8PRIxPTR, *stack++); + } + msg.Append("\n"); + msg.WriteToLogFile(); +#endif +} + + void Logger::DebugTag(const char* call_site_tag) { #ifdef ENABLE_LOGGING_AND_PROFILING if (!Log::IsEnabled() || !FLAG_log) return; diff --git a/src/log.h b/src/log.h index 07a0429ac..13d45d2e3 100644 --- a/src/log.h +++ b/src/log.h @@ -223,6 +223,8 @@ class Logger { int number, int bytes); static void HeapSampleJSRetainersEvent(const char* constructor, const char* event); + static void HeapSampleJSProducerEvent(const char* constructor, + Address* stack); static void HeapSampleStats(const char* space, const char* kind, int capacity, int used); diff --git a/tools/tickprocessor.js b/tools/tickprocessor.js index 84f0eea58..fd23987d9 100644 --- a/tools/tickprocessor.js +++ b/tools/tickprocessor.js @@ -75,7 +75,18 @@ function TickProcessor( 'tick': { parsers: [this.createAddressParser('code'), this.createAddressParser('stack'), parseInt, 'var-args'], processor: this.processTick, backrefs: true }, + 'heap-sample-begin': { parsers: [null, null, parseInt], + processor: this.processHeapSampleBegin }, + 'heap-sample-end': { parsers: [null, null], + processor: this.processHeapSampleEnd }, + 'heap-js-prod-item': { parsers: [null, 'var-args'], + processor: this.processJSProducer, backrefs: true }, + // Ignored events. 'profiler': null, + 'heap-sample-stats': null, + 'heap-sample-item': null, + 'heap-js-cons-item': null, + 'heap-js-ret-item': null, // Obsolete row types. 'code-allocate': null, 'begin-code-region': null, @@ -113,6 +124,9 @@ function TickProcessor( // Count each tick as a time unit. this.viewBuilder_ = new devtools.profiler.ViewBuilder(1); this.lastLogFileName_ = null; + + this.generation_ = 1; + this.currentProducerProfile_ = null; }; inherits(TickProcessor, devtools.profiler.LogReader); @@ -220,6 +234,41 @@ TickProcessor.prototype.processTick = function(pc, sp, vmState, stack) { }; +TickProcessor.prototype.processHeapSampleBegin = function(space, state, ticks) { + if (space != 'Heap') return; + this.currentProducerProfile_ = new devtools.profiler.CallTree(); +}; + + +TickProcessor.prototype.processHeapSampleEnd = function(space, state) { + if (space != 'Heap' || !this.currentProducerProfile_) return; + + print('Generation ' + this.generation_ + ':'); + var tree = this.currentProducerProfile_; + tree.computeTotalWeights(); + var producersView = this.viewBuilder_.buildView(tree); + // Sort by total time, desc, then by name, desc. + producersView.sort(function(rec1, rec2) { + return rec2.totalTime - rec1.totalTime || + (rec2.internalFuncName < rec1.internalFuncName ? -1 : 1); }); + this.printHeavyProfile(producersView.head.children); + + this.currentProducerProfile_ = null; + this.generation_++; +}; + + +TickProcessor.prototype.processJSProducer = function(constructor, stack) { + if (!this.currentProducerProfile_) return; + if (stack.length == 0) return; + var first = stack.shift(); + var processedStack = + this.profile_.resolveAndFilterFuncs_(this.processStack(first, stack)); + processedStack.unshift(constructor); + this.currentProducerProfile_.addPath(processedStack); +}; + + TickProcessor.prototype.printStatistics = function() { print('Statistical profiling result from ' + this.lastLogFileName_ + ', (' + this.ticks_.total +