Revision: 15530
Author: [email protected]
Date: Sun Jul 7 04:42:30 2013
Log: CPUProfiler: Improve line numbers support in profiler.
1) report line number even if a script has no resource_name (evals);
a) do that for already compiled functions in log.cc;
b) do that for fresh evals in compiler.cc;
2) Implement the test for LineNumbers and make it fast and stable,
otherwise we have to wait for tick samples;
a) move processor_->Join() call into new Processor::StopSynchronously
method;
b) Process all the CodeEvents even if we are stopping Processor thread;
c) make getters for generator and processor;
3) Fix the test for Jit that didn't expect line numbers;
4) Minor refactoring:
a) in ProcessTicks;
b) rename enqueue_order_ to last_code_event_id_ for better readability;
c) rename dequeue_order_ to last_processed_code_event_id_ and make it a
member for better readability;
BUG=
TEST=test-profile-generator/LineNumber
[email protected], [email protected]
Review URL: https://codereview.chromium.org/18058008
http://code.google.com/p/v8/source/detail?r=15530
Modified:
/branches/bleeding_edge/src/compiler.cc
/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/log.cc
/branches/bleeding_edge/test/cctest/test-api.cc
/branches/bleeding_edge/test/cctest/test-cpu-profiler.cc
/branches/bleeding_edge/test/cctest/test-profile-generator.cc
=======================================
--- /branches/bleeding_edge/src/compiler.cc Fri Jul 5 02:52:11 2013
+++ /branches/bleeding_edge/src/compiler.cc Sun Jul 7 04:42:30 2013
@@ -1200,9 +1200,9 @@
Handle<Code> code = info->code();
if (*code ==
info->isolate()->builtins()->builtin(Builtins::kLazyCompile))
return;
+ int line_num = GetScriptLineNumber(script, shared->start_position()) +
1;
+ USE(line_num);
if (script->name()->IsString()) {
- int line_num = GetScriptLineNumber(script, shared->start_position())
+ 1;
- USE(line_num);
PROFILE(info->isolate(),
CodeCreateEvent(Logger::ToNativeByScript(tag, *script),
*code,
@@ -1216,7 +1216,8 @@
*code,
*shared,
info,
- shared->DebugName()));
+ info->isolate()->heap()->empty_string(),
+ line_num));
}
}
=======================================
--- /branches/bleeding_edge/src/cpu-profiler-inl.h Tue Jul 2 00:51:09 2013
+++ /branches/bleeding_edge/src/cpu-profiler-inl.h Sun Jul 7 04:42:30 2013
@@ -70,7 +70,7 @@
TickSample* ProfilerEventsProcessor::TickSampleEvent() {
generator_->Tick();
TickSampleEventRecord* evt =
- new(ticks_buffer_.Enqueue()) TickSampleEventRecord(enqueue_order_);
+ new(ticks_buffer_.Enqueue())
TickSampleEventRecord(last_code_event_id_);
return &evt->sample;
}
=======================================
--- /branches/bleeding_edge/src/cpu-profiler.cc Sat Jul 6 02:12:09 2013
+++ /branches/bleeding_edge/src/cpu-profiler.cc Sun Jul 7 04:42:30 2013
@@ -52,18 +52,18 @@
ticks_buffer_(sizeof(TickSampleEventRecord),
kTickSamplesBufferChunkSize,
kTickSamplesBufferChunksCount),
- enqueue_order_(0) {
+ last_code_event_id_(0), last_processed_code_event_id_(0) {
}
void ProfilerEventsProcessor::Enqueue(const CodeEventsContainer& event) {
- event.generic.order = ++enqueue_order_;
+ event.generic.order = ++last_code_event_id_;
events_buffer_.Enqueue(event);
}
void ProfilerEventsProcessor::AddCurrentStack(Isolate* isolate) {
- TickSampleEventRecord record(enqueue_order_);
+ TickSampleEventRecord record(last_code_event_id_);
TickSample* sample = &record.sample;
sample->state = isolate->current_vm_state();
sample->pc = reinterpret_cast<Address>(sample); // Not NULL.
@@ -76,7 +76,14 @@
}
-bool ProfilerEventsProcessor::ProcessCodeEvent(unsigned* dequeue_order) {
+void ProfilerEventsProcessor::StopSynchronously() {
+ if (!running_) return;
+ running_ = false;
+ Join();
+}
+
+
+bool ProfilerEventsProcessor::ProcessCodeEvent() {
CodeEventsContainer record;
if (events_buffer_.Dequeue(&record)) {
switch (record.generic.type) {
@@ -90,17 +97,18 @@
#undef PROFILER_TYPE_CASE
default: return true; // Skip record.
}
- *dequeue_order = record.generic.order;
+ last_processed_code_event_id_ = record.generic.order;
return true;
}
return false;
}
-bool ProfilerEventsProcessor::ProcessTicks(unsigned dequeue_order) {
+bool ProfilerEventsProcessor::ProcessTicks() {
while (true) {
if (!ticks_from_vm_buffer_.IsEmpty()
- && ticks_from_vm_buffer_.Peek()->order == dequeue_order) {
+ && ticks_from_vm_buffer_.Peek()->order ==
+ last_processed_code_event_id_) {
TickSampleEventRecord record;
ticks_from_vm_buffer_.Dequeue(&record);
generator_->RecordTickSample(record.sample);
@@ -115,38 +123,35 @@
// will get far behind, a record may be modified right under its
// feet.
TickSampleEventRecord record = *rec;
- if (record.order == dequeue_order) {
- // A paranoid check to make sure that we don't get a memory overrun
- // in case of frames_count having a wild value.
- if (record.sample.frames_count < 0
- || record.sample.frames_count > TickSample::kMaxFramesCount)
- record.sample.frames_count = 0;
- generator_->RecordTickSample(record.sample);
- ticks_buffer_.FinishDequeue();
- } else {
- return true;
- }
+ if (record.order != last_processed_code_event_id_) return true;
+
+ // A paranoid check to make sure that we don't get a memory overrun
+ // in case of frames_count having a wild value.
+ if (record.sample.frames_count < 0
+ || record.sample.frames_count > TickSample::kMaxFramesCount)
+ record.sample.frames_count = 0;
+ generator_->RecordTickSample(record.sample);
+ ticks_buffer_.FinishDequeue();
}
}
void ProfilerEventsProcessor::Run() {
- unsigned dequeue_order = 0;
-
while (running_) {
// Process ticks until we have any.
- if (ProcessTicks(dequeue_order)) {
- // All ticks of the current dequeue_order are processed,
+ if (ProcessTicks()) {
+ // All ticks of the current last_processed_code_event_id_ are
processed,
// proceed to the next code event.
- ProcessCodeEvent(&dequeue_order);
+ ProcessCodeEvent();
}
YieldCPU();
}
// Process remaining tick events.
ticks_buffer_.FlushResidualRecords();
- // Perform processing until we have tick events, skip remaining code
events.
- while (ProcessTicks(dequeue_order) && ProcessCodeEvent(&dequeue_order))
{ }
+ do {
+ ProcessTicks();
+ } while (ProcessCodeEvent());
}
@@ -480,8 +485,7 @@
need_to_stop_sampler_ = false;
}
is_profiling_ = false;
- processor_->Stop();
- processor_->Join();
+ processor_->StopSynchronously();
delete processor_;
delete generator_;
processor_ = NULL;
=======================================
--- /branches/bleeding_edge/src/cpu-profiler.h Sat Jul 6 02:12:09 2013
+++ /branches/bleeding_edge/src/cpu-profiler.h Sun Jul 7 04:42:30 2013
@@ -155,7 +155,7 @@
// Thread control.
virtual void Run();
- inline void Stop() { running_ = false; }
+ void StopSynchronously();
INLINE(bool running()) { return running_; }
void Enqueue(const CodeEventsContainer& event);
@@ -170,15 +170,16 @@
private:
// Called from events processing thread (Run() method.)
- bool ProcessCodeEvent(unsigned* dequeue_order);
- bool ProcessTicks(unsigned dequeue_order);
+ bool ProcessCodeEvent();
+ bool ProcessTicks();
ProfileGenerator* generator_;
bool running_;
UnboundQueue<CodeEventsContainer> events_buffer_;
SamplingCircularQueue ticks_buffer_;
UnboundQueue<TickSampleEventRecord> ticks_from_vm_buffer_;
- unsigned enqueue_order_;
+ unsigned last_code_event_id_;
+ unsigned last_processed_code_event_id_;
};
@@ -247,6 +248,9 @@
bool* is_profiling_address() {
return &is_profiling_;
}
+
+ ProfileGenerator* generator() const { return generator_; }
+ ProfilerEventsProcessor* processor() const { return processor_; }
private:
void StartProcessorIfNotStarted();
=======================================
--- /branches/bleeding_edge/src/log.cc Fri Jul 5 02:52:11 2013
+++ /branches/bleeding_edge/src/log.cc Sun Jul 7 04:42:30 2013
@@ -1659,15 +1659,15 @@
Handle<String> func_name(shared->DebugName());
if (shared->script()->IsScript()) {
Handle<Script> script(Script::cast(shared->script()));
+ int line_num = GetScriptLineNumber(script, shared->start_position()) +
1;
if (script->name()->IsString()) {
Handle<String> script_name(String::cast(script->name()));
- int line_num = GetScriptLineNumber(script, shared->start_position());
if (line_num > 0) {
PROFILE(isolate_,
CodeCreateEvent(
Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG,
*script),
*code, *shared, NULL,
- *script_name, line_num + 1));
+ *script_name, line_num));
} else {
// Can't distinguish eval and script here, so always use Script.
PROFILE(isolate_,
@@ -1679,7 +1679,8 @@
PROFILE(isolate_,
CodeCreateEvent(
Logger::ToNativeByScript(Logger::LAZY_COMPILE_TAG,
*script),
- *code, *shared, NULL, *func_name));
+ *code, *shared, NULL,
+ isolate_->heap()->empty_string(), line_num));
}
} else if (shared->IsApiFunction()) {
// API function.
=======================================
--- /branches/bleeding_edge/test/cctest/test-api.cc Fri Jul 5 03:12:36 2013
+++ /branches/bleeding_edge/test/cctest/test-api.cc Sun Jul 7 04:42:30 2013
@@ -12730,13 +12730,18 @@
const char* tail = event->name.str + kPreambleLen;
size_t tail_len = event->name.len - kPreambleLen;
size_t expected_len = strlen(expected);
- if (tail_len == expected_len + 1) {
- if (*tail == '*' || *tail == '~') {
- --tail_len;
- ++tail;
- } else {
- return false;
- }
+ if (tail_len > 1 && (*tail == '*' || *tail == '~')) {
+ --tail_len;
+ ++tail;
+ }
+
+ // Check for tails like 'bar :1'.
+ if (tail_len > expected_len + 2 &&
+ tail[expected_len] == ' ' &&
+ tail[expected_len + 1] == ':' &&
+ tail[expected_len + 2] &&
+ !strncmp(tail, expected, expected_len)) {
+ return true;
}
if (tail_len != expected_len)
=======================================
--- /branches/bleeding_edge/test/cctest/test-cpu-profiler.cc Sat Jul 6
02:12:09 2013
+++ /branches/bleeding_edge/test/cctest/test-cpu-profiler.cc Sun Jul 7
04:42:30 2013
@@ -52,7 +52,7 @@
ProfileGenerator generator(&profiles);
ProfilerEventsProcessor processor(&generator);
processor.Start();
- processor.Stop();
+ processor.StopSynchronously();
processor.Join();
}
@@ -160,7 +160,7 @@
// Enqueue a tick event to enable code events processing.
EnqueueTickSampleEvent(&processor, aaa_code->address());
- processor.Stop();
+ processor.StopSynchronously();
processor.Join();
// Check the state of profile generator.
@@ -222,7 +222,7 @@
frame2_code->instruction_end() - 1,
frame1_code->instruction_end() - 1);
- processor.Stop();
+ processor.StopSynchronously();
processor.Join();
CpuProfile* profile = profiles->StopProfiling("", 1);
CHECK_NE(NULL, profile);
@@ -286,7 +286,7 @@
sample->stack[i] = code->address();
}
- processor.Stop();
+ processor.StopSynchronously();
processor.Join();
CpuProfile* profile = profiles->StopProfiling("", 1);
CHECK_NE(NULL, profile);
=======================================
--- /branches/bleeding_edge/test/cctest/test-profile-generator.cc Sat Jul
6 02:12:09 2013
+++ /branches/bleeding_edge/test/cctest/test-profile-generator.cc Sun Jul
7 04:42:30 2013
@@ -826,3 +826,59 @@
}
+
+
+static const char* line_number_test_source_existing_functions =
+"function foo_at_the_first_line() {\n"
+"}\n"
+"foo_at_the_first_line();\n"
+"function lazy_func_at_forth_line() {}\n";
+
+
+static const char* line_number_test_source_profile_time_functions =
+"// Empty first line\n"
+"function bar_at_the_second_line() {\n"
+" foo_at_the_first_line();\n"
+"}\n"
+"bar_at_the_second_line();\n"
+"function lazy_func_at_6th_line() {}";
+
+int GetFunctionLineNumber(LocalContext* env, const char* name) {
+ CpuProfiler* profiler = i::Isolate::Current()->cpu_profiler();
+ CodeMap* code_map = profiler->generator()->code_map();
+ i::Handle<i::JSFunction> func = v8::Utils::OpenHandle(
+ *v8::Local<v8::Function>::Cast(
+ (*(*env))->Global()->Get(v8_str(name))));
+ CodeEntry* func_entry = code_map->FindEntry(func->code()->address());
+ if (!func_entry)
+ FATAL(name);
+ return func_entry->line_number();
+}
+
+
+TEST(LineNumber) {
+ i::FLAG_use_inlining = false;
+
+ CcTest::InitializeVM();
+ LocalContext env;
+ i::Isolate* isolate = i::Isolate::Current();
+ TestSetup test_setup;
+
+ i::HandleScope scope(isolate);
+
+ CompileRun(line_number_test_source_existing_functions);
+
+ CpuProfiler* profiler = isolate->cpu_profiler();
+ profiler->StartProfiling("LineNumber");
+
+ CompileRun(line_number_test_source_profile_time_functions);
+
+ profiler->processor()->StopSynchronously();
+
+ CHECK_EQ(1, GetFunctionLineNumber(&env, "foo_at_the_first_line"));
+ CHECK_EQ(0, GetFunctionLineNumber(&env, "lazy_func_at_forth_line"));
+ CHECK_EQ(2, GetFunctionLineNumber(&env, "bar_at_the_second_line"));
+ CHECK_EQ(0, GetFunctionLineNumber(&env, "lazy_func_at_6th_line"));
+
+ profiler->StopProfiling("LineNumber");
+}
--
--
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.
