Revision: 15426
Author: [email protected]
Date: Mon Jul 1 07:57:58 2013
Log: Correctly report callstack when current function is FunctionCall
builtin
When current function is FunctionCall builtin we have no reliable way to
determine its caller function (in many cases the top of the sampled stack
contains address of the caller but sometimes it does not). Instead of
dropping the sample or its two top frames we simply mark the caller frame
as '(unresolved function)'. It seems like a better approach that dropping
whole sample as knowing the top function and the rest of the stack the user
should be able to figure out what the caller was.
This change adds builtin id to CodeEntry objects. It will be used later to
add similar top frame analysis for FunctionApply and probably other
builtins.
BUG=None
[email protected], [email protected]
Review URL: https://codereview.chromium.org/18316004
http://code.google.com/p/v8/source/detail?r=15426
Modified:
/branches/bleeding_edge/src/cpu-profiler-inl.h
/branches/bleeding_edge/src/cpu-profiler.cc
/branches/bleeding_edge/src/cpu-profiler.h
/branches/bleeding_edge/src/profile-generator-inl.h
/branches/bleeding_edge/src/profile-generator.cc
/branches/bleeding_edge/src/profile-generator.h
/branches/bleeding_edge/test/cctest/test-cpu-profiler.cc
=======================================
--- /branches/bleeding_edge/src/cpu-profiler-inl.h Mon Jul 1 03:12:03 2013
+++ /branches/bleeding_edge/src/cpu-profiler-inl.h Mon Jul 1 07:57:58 2013
@@ -54,6 +54,17 @@
void SharedFunctionInfoMoveEventRecord::UpdateCodeMap(CodeMap* code_map) {
code_map->MoveCode(from, to);
}
+
+
+void ReportBuiltinEventRecord::UpdateCodeMap(CodeMap* code_map) {
+ CodeEntry* entry = code_map->FindEntry(start);
+ if (!entry) {
+ // Code objects for builtins should already have been added to the map.
+ UNREACHABLE();
+ return;
+ }
+ entry->SetBuiltinId(builtin_id);
+}
TickSample* ProfilerEventsProcessor::TickSampleEvent() {
=======================================
--- /branches/bleeding_edge/src/cpu-profiler.cc Mon Jul 1 05:32:52 2013
+++ /branches/bleeding_edge/src/cpu-profiler.cc Mon Jul 1 07:57:58 2013
@@ -446,6 +446,7 @@
}
logger->LogCompiledFunctions();
logger->LogAccessorCallbacks();
+ LogBuiltins();
// Enable stack sampling.
Sampler* sampler = logger->sampler();
sampler->IncreaseProfilingDepth();
@@ -504,6 +505,20 @@
generator_ = NULL;
logger->logging_nesting_ = saved_logging_nesting_;
}
+
+
+void CpuProfiler::LogBuiltins() {
+ Builtins* builtins = isolate_->builtins();
+ ASSERT(builtins->is_initialized());
+ for (int i = 0; i < Builtins::builtin_count; i++) {
+ CodeEventsContainer evt_rec(CodeEventRecord::REPORT_BUILTIN);
+ ReportBuiltinEventRecord* rec = &evt_rec.ReportBuiltinEventRecord_;
+ Builtins::Name id = static_cast<Builtins::Name>(i);
+ rec->start = builtins->builtin(id)->address();
+ rec->builtin_id = id;
+ processor_->Enqueue(evt_rec);
+ }
+}
} } // namespace v8::internal
=======================================
--- /branches/bleeding_edge/src/cpu-profiler.h Mon Jul 1 05:24:26 2013
+++ /branches/bleeding_edge/src/cpu-profiler.h Mon Jul 1 07:57:58 2013
@@ -49,7 +49,8 @@
#define CODE_EVENTS_TYPE_LIST(V) \
V(CODE_CREATION, CodeCreateEventRecord) \
V(CODE_MOVE, CodeMoveEventRecord) \
- V(SHARED_FUNC_MOVE, SharedFunctionInfoMoveEventRecord)
+ V(SHARED_FUNC_MOVE, SharedFunctionInfoMoveEventRecord) \
+ V(REPORT_BUILTIN, ReportBuiltinEventRecord)
class CodeEventRecord {
@@ -96,6 +97,15 @@
};
+class ReportBuiltinEventRecord : public CodeEventRecord {
+ public:
+ Address start;
+ Builtins::Name builtin_id;
+
+ INLINE(void UpdateCodeMap(CodeMap* code_map));
+};
+
+
class TickSampleEventRecord {
public:
// The parameterless constructor is used when we dequeue data from
@@ -246,6 +256,7 @@
void StopProcessorIfLastProfile(const char* title);
void StopProcessor();
void ResetProfiles();
+ void LogBuiltins();
Isolate* isolate_;
CpuProfilesCollection* profiles_;
=======================================
--- /branches/bleeding_edge/src/profile-generator-inl.h Mon Jul 1 03:12:03
2013
+++ /branches/bleeding_edge/src/profile-generator-inl.h Mon Jul 1 07:57:58
2013
@@ -50,6 +50,7 @@
const char* resource_name,
int line_number)
: tag_(tag),
+ builtin_id_(Builtins::builtin_count),
name_prefix_(name_prefix),
name_(name),
resource_name_(resource_name),
=======================================
--- /branches/bleeding_edge/src/profile-generator.cc Mon Jul 1 03:12:03
2013
+++ /branches/bleeding_edge/src/profile-generator.cc Mon Jul 1 07:57:58
2013
@@ -233,6 +233,12 @@
&& resource_name_ == entry->resource_name_
&& line_number_ == entry->line_number_)));
}
+
+
+void CodeEntry::SetBuiltinId(Builtins::Name id) {
+ tag_ = Logger::BUILTIN_TAG;
+ builtin_id_ = id;
+}
ProfileNode* ProfileNode::FindChild(CodeEntry* entry) {
@@ -847,6 +853,8 @@
"(program)";
const char* const ProfileGenerator::kGarbageCollectorEntryName =
"(garbage collector)";
+const char* const ProfileGenerator::kUnresolvedFunctionName =
+ "(unresolved function)";
ProfileGenerator::ProfileGenerator(CpuProfilesCollection* profiles)
@@ -855,7 +863,10 @@
profiles->NewCodeEntry(Logger::FUNCTION_TAG, kProgramEntryName)),
gc_entry_(
profiles->NewCodeEntry(Logger::BUILTIN_TAG,
- kGarbageCollectorEntryName)) {
+ kGarbageCollectorEntryName)),
+ unresolved_entry_(
+ profiles->NewCodeEntry(Logger::FUNCTION_TAG,
+ kUnresolvedFunctionName)) {
}
@@ -867,33 +878,40 @@
CodeEntry** entry = entries.start();
memset(entry, 0, entries.length() * sizeof(*entry));
if (sample.pc != NULL) {
- Address start;
- CodeEntry* pc_entry = code_map_.FindEntry(sample.pc, &start);
- // If pc is in the function code before it set up stack frame or after
the
- // frame was destroyed SafeStackFrameIterator incorrectly thinks that
- // ebp contains return address of the current function and skips
caller's
- // frame. Check for this case and just skip such samples.
- if (pc_entry) {
- List<OffsetRange>* ranges = pc_entry->no_frame_ranges();
- if (ranges) {
- Code* code = Code::cast(HeapObject::FromAddress(start));
- int pc_offset = static_cast<int>(sample.pc -
code->instruction_start());
- for (int i = 0; i < ranges->length(); i++) {
- OffsetRange& range = ranges->at(i);
- if (range.from <= pc_offset && pc_offset < range.to) {
- return;
- }
- }
- }
- }
- *entry++ = pc_entry;
-
if (sample.has_external_callback) {
// Don't use PC when in external callback code, as it can point
// inside callback's code, and we will erroneously report
// that a callback calls itself.
- *(entries.start()) = NULL;
*entry++ = code_map_.FindEntry(sample.external_callback);
+ } else {
+ Address start;
+ CodeEntry* pc_entry = code_map_.FindEntry(sample.pc, &start);
+ // If pc is in the function code before it set up stack frame or
after the
+ // frame was destroyed SafeStackFrameIterator incorrectly thinks that
+ // ebp contains return address of the current function and skips
caller's
+ // frame. Check for this case and just skip such samples.
+ if (pc_entry) {
+ List<OffsetRange>* ranges = pc_entry->no_frame_ranges();
+ if (ranges) {
+ Code* code = Code::cast(HeapObject::FromAddress(start));
+ int pc_offset = static_cast<int>(
+ sample.pc - code->instruction_start());
+ for (int i = 0; i < ranges->length(); i++) {
+ OffsetRange& range = ranges->at(i);
+ if (range.from <= pc_offset && pc_offset < range.to) {
+ return;
+ }
+ }
+ }
+ *entry++ = pc_entry;
+
+ if (pc_entry->builtin_id() == Builtins::kFunctionCall) {
+ // When current function is FunctionCall builtin tos is sometimes
+ // address of the function that invoked it but sometimes it's one
+ // of the arguments. We simply replace the frame with 'unknown'
entry.
+ *entry++ = unresolved_entry_;
+ }
+ }
}
for (const Address* stack_pos = sample.stack,
=======================================
--- /branches/bleeding_edge/src/profile-generator.h Mon Jul 1 03:12:03 2013
+++ /branches/bleeding_edge/src/profile-generator.h Mon Jul 1 07:57:58 2013
@@ -119,6 +119,9 @@
void set_no_frame_ranges(List<OffsetRange>* ranges) {
no_frame_ranges_ = ranges;
}
+
+ void SetBuiltinId(Builtins::Name id);
+ Builtins::Name builtin_id() const { return builtin_id_; }
void CopyData(const CodeEntry& source);
uint32_t GetCallUid() const;
@@ -128,7 +131,8 @@
static const char* const kEmptyResourceName;
private:
- Logger::LogEventsAndTags tag_;
+ Logger::LogEventsAndTags tag_ : 8;
+ Builtins::Name builtin_id_ : 8;
const char* name_prefix_;
const char* name_;
const char* resource_name_;
@@ -422,6 +426,9 @@
static const char* const kAnonymousFunctionName;
static const char* const kProgramEntryName;
static const char* const kGarbageCollectorEntryName;
+ // Used to represent frames for which we have no reliable way to
+ // detect function.
+ static const char* const kUnresolvedFunctionName;
private:
INLINE(CodeEntry* EntryForVMState(StateTag tag));
@@ -430,6 +437,7 @@
CodeMap code_map_;
CodeEntry* program_entry_;
CodeEntry* gc_entry_;
+ CodeEntry* unresolved_entry_;
SampleRateCalculator sample_rate_calc_;
DISALLOW_COPY_AND_ASSIGN(ProfileGenerator);
=======================================
--- /branches/bleeding_edge/test/cctest/test-cpu-profiler.cc Mon Jul 1
05:32:52 2013
+++ /branches/bleeding_edge/test/cctest/test-cpu-profiler.cc Mon Jul 1
07:57:58 2013
@@ -1023,3 +1023,80 @@
cpu_profiler->DeleteAllCpuProfiles();
}
+
+
+static const char* call_function_test_source = "function bar(iterations)
{\n"
+"}\n"
+"function start(duration) {\n"
+" var start = Date.now();\n"
+" while (Date.now() - start < duration) {\n"
+" try {\n"
+" bar.call(this, 10 * 1000);\n"
+" } catch(e) {}\n"
+" }\n"
+"}";
+
+
+// Test that if we sampled thread when it was inside FunctionCall buitin
then
+// its caller frame will be '(unresolved function)' as we have no reliable
way
+// to resolve it.
+//
+// [Top down]:
+// 96 0 (root) [-1] #1
+// 1 1 (garbage collector) [-1] #4
+// 5 0 (unresolved function) [-1] #5
+// 5 5 call [-1] #6
+// 71 70 start [-1] #3
+// 1 1 bar [-1] #7
+// 19 19 (program) [-1] #2
+TEST(FunctionCallSample) {
+ LocalContext env;
+ v8::HandleScope scope(env->GetIsolate());
+
+ v8::Script::Compile(v8::String::New(call_function_test_source))->Run();
+ v8::Local<v8::Function> function = v8::Local<v8::Function>::Cast(
+ env->Global()->Get(v8::String::New("start")));
+
+ v8::CpuProfiler* cpu_profiler = env->GetIsolate()->GetCpuProfiler();
+ v8::Local<v8::String> profile_name = v8::String::New("my_profile");
+
+ cpu_profiler->StartCpuProfiling(profile_name);
+ int32_t duration_ms = 100;
+ v8::Handle<v8::Value> args[] = { v8::Integer::New(duration_ms) };
+ function->Call(env->Global(), ARRAY_SIZE(args), args);
+ const v8::CpuProfile* profile =
cpu_profiler->StopCpuProfiling(profile_name);
+
+ CHECK_NE(NULL, profile);
+ // Dump collected profile to have a better diagnostic in case of failure.
+ reinterpret_cast<i::CpuProfile*>(
+ const_cast<v8::CpuProfile*>(profile))->Print();
+
+ const v8::CpuProfileNode* root = profile->GetTopDownRoot();
+ {
+ ScopedVector<v8::Handle<v8::String> > names(4);
+ names[0] =
v8::String::New(ProfileGenerator::kGarbageCollectorEntryName);
+ names[1] = v8::String::New(ProfileGenerator::kProgramEntryName);
+ names[2] = v8::String::New("start");
+ names[3] =
v8::String::New(i::ProfileGenerator::kUnresolvedFunctionName);
+ // Don't allow |bar| and |call| nodes to be at the top level.
+ CheckChildrenNames(root, names);
+ }
+
+ const v8::CpuProfileNode* startNode = GetChild(root, "start");
+ {
+ ScopedVector<v8::Handle<v8::String> > names(1);
+ names[0] = v8::String::New("bar");
+ CheckChildrenNames(startNode, names);
+ }
+
+ const v8::CpuProfileNode* unresolvedNode =
+ FindChild(root, i::ProfileGenerator::kUnresolvedFunctionName);
+ if (unresolvedNode) {
+ ScopedVector<v8::Handle<v8::String> > names(1);
+ names[0] = v8::String::New("call");
+ CheckChildrenNames(unresolvedNode, names);
+ }
+
+ cpu_profiler->DeleteAllCpuProfiles();
+}
+
--
--
v8-dev mailing list
[email protected]
http://groups.google.com/group/v8-dev
---
You received this message because you are subscribed to the Google Groups "v8-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
For more options, visit https://groups.google.com/groups/opt_out.
