Revision: 3673
Author: [email protected]
Date: Thu Jan 21 08:42:41 2010
Log: Fix issue 553: function frame is skipped in profile when compare stub
is called.
The problem appeared due to a fact that stubs doesn't create a stack
frame, reusing the stack frame of the caller function. When building
stack traces, the current function is retrieved from PC, and its
callees are retrieved by traversing the stack backwards. Thus, for
stubs, the stub itself was discovered via PC, and then stub's caller's
caller was retrieved from stack.
To fix this problem, a pointer to JSFunction object is now captured
from the topmost stack frame, and is saved into stack trace log
record. Then a simple heuristics is applied whether a referred
function should be added to decoded stack, or not, to avoid reporting
the same function twice (from PC and from the pointer.)
BUG=553
TEST=added to mjsunit/tools/tickprocessor
Review URL: http://codereview.chromium.org/546089
http://code.google.com/p/v8/source/detail?r=3673
Added:
/branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test-func-info.log
/branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test.func-info
Modified:
/branches/bleeding_edge/src/frames.h
/branches/bleeding_edge/src/handles.cc
/branches/bleeding_edge/src/log.cc
/branches/bleeding_edge/src/log.h
/branches/bleeding_edge/src/mark-compact.cc
/branches/bleeding_edge/src/mark-compact.h
/branches/bleeding_edge/src/platform-freebsd.cc
/branches/bleeding_edge/src/platform-linux.cc
/branches/bleeding_edge/src/platform-macos.cc
/branches/bleeding_edge/src/platform-win32.cc
/branches/bleeding_edge/src/platform.h
/branches/bleeding_edge/src/runtime.cc
/branches/bleeding_edge/src/spaces.cc
/branches/bleeding_edge/test/cctest/test-log-stack-tracer.cc
/branches/bleeding_edge/test/cctest/test-log.cc
/branches/bleeding_edge/test/mjsunit/tools/logreader.js
/branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test.log
/branches/bleeding_edge/test/mjsunit/tools/tickprocessor.js
/branches/bleeding_edge/tools/codemap.js
/branches/bleeding_edge/tools/logreader.js
/branches/bleeding_edge/tools/profile.js
/branches/bleeding_edge/tools/tickprocessor.js
/branches/bleeding_edge/tools/tickprocessor.py
=======================================
--- /dev/null
+++
/branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test-func-info.log
Thu Jan 21 08:42:41 2010
@@ -0,0 +1,13 @@
+shared-library,"shell",0x08048000,0x081ee000
+shared-library,"/lib32/libm-2.7.so",0xf7db6000,0xf7dd9000
+shared-library,"ffffe000-fffff000",0xffffe000,0xfffff000
+profiler,"begin",1
+code-creation,Stub,0x424260,348,"CompareStub_GE"
+code-creation,LazyCompile,0x2a8100,18535,"DrawQube 3d-cube.js:188"
+function-creation,0x2d11b8,0x2a8100
+code-creation,LazyCompile,0x480100,3908,"DrawLine 3d-cube.js:17"
+function-creation,0x2d0f7c,0x480100
+tick,0x424284,0xbfffeea0,0x2d0f7c,0,0x2aaaa5
+tick,0x42429f,0xbfffed88,0x2d0f7c,0,0x2aacb4
+tick,0x48063d,0xbfffec7c,0x2d0f7c,0,0x2aaec6
+profiler,"end"
=======================================
--- /dev/null
+++ /branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test.func-info
Thu Jan 21 08:42:41 2010
@@ -0,0 +1,29 @@
+Statistical profiling result from v8.log, (3 ticks, 0 unaccounted, 0
excluded).
+
+ [Shared libraries]:
+ ticks total nonlib name
+
+ [JavaScript]:
+ ticks total nonlib name
+ 2 66.7% 66.7% Stub: CompareStub_GE
+ 1 33.3% 33.3% LazyCompile: DrawLine 3d-cube.js:17
+
+ [C++]:
+ ticks total nonlib name
+
+ [GC]:
+ ticks total nonlib name
+ 0 0.0%
+
+ [Bottom up (heavy) profile]:
+ Note: percentage shows a share of a particular caller in the total
+ amount of its parent calls.
+ Callers occupying less than 2.0% are not shown.
+
+ ticks parent name
+ 2 66.7% Stub: CompareStub_GE
+ 2 100.0% LazyCompile: DrawLine 3d-cube.js:17
+ 2 100.0% LazyCompile: DrawQube 3d-cube.js:188
+
+ 1 33.3% LazyCompile: DrawLine 3d-cube.js:17
+ 1 100.0% LazyCompile: DrawQube 3d-cube.js:188
=======================================
--- /branches/bleeding_edge/src/frames.h Wed Nov 4 00:51:48 2009
+++ /branches/bleeding_edge/src/frames.h Thu Jan 21 08:42:41 2010
@@ -607,11 +607,12 @@
void Advance();
void Reset();
- private:
static bool IsWithinBounds(
Address low_bound, Address high_bound, Address addr) {
return low_bound <= addr && addr <= high_bound;
}
+
+ private:
bool IsValidStackAddress(Address addr) const {
return IsWithinBounds(low_bound_, high_bound_, addr);
}
=======================================
--- /branches/bleeding_edge/src/handles.cc Tue Dec 1 02:25:29 2009
+++ /branches/bleeding_edge/src/handles.cc Thu Jan 21 08:42:41 2010
@@ -681,14 +681,18 @@
bool CompileLazy(Handle<JSFunction> function, ClearExceptionFlag flag) {
// Compile the source information to a code object.
Handle<SharedFunctionInfo> shared(function->shared());
- return CompileLazyShared(shared, flag, 0);
+ bool result = CompileLazyShared(shared, flag, 0);
+ LOG(FunctionCreateEvent(*function));
+ return result;
}
bool CompileLazyInLoop(Handle<JSFunction> function, ClearExceptionFlag
flag) {
// Compile the source information to a code object.
Handle<SharedFunctionInfo> shared(function->shared());
- return CompileLazyShared(shared, flag, 1);
+ bool result = CompileLazyShared(shared, flag, 1);
+ LOG(FunctionCreateEvent(*function));
+ return result;
}
OptimizedObjectForAddingMultipleProperties::
=======================================
--- /branches/bleeding_edge/src/log.cc Mon Jan 18 08:04:25 2010
+++ /branches/bleeding_edge/src/log.cc Thu Jan 21 08:42:41 2010
@@ -154,6 +154,13 @@
sample->frames_count = 0;
return;
}
+
+ const Address functionAddr =
+ sample->fp + JavaScriptFrameConstants::kFunctionOffset;
+ if (SafeStackFrameIterator::IsWithinBounds(sample->sp, js_entry_sp,
+ functionAddr)) {
+ sample->function = Memory::Address_at(functionAddr) - kHeapObjectTag;
+ }
int i = 0;
const Address callback = Logger::current_state_ != NULL ?
@@ -162,11 +169,8 @@
sample->stack[i++] = callback;
}
- SafeStackTraceFrameIterator it(
- reinterpret_cast<Address>(sample->fp),
- reinterpret_cast<Address>(sample->sp),
- reinterpret_cast<Address>(sample->sp),
- js_entry_sp);
+ SafeStackTraceFrameIterator it(sample->fp, sample->sp,
+ sample->sp, js_entry_sp);
while (!it.done() && i < TickSample::kMaxFramesCount) {
sample->stack[i++] = it.frame()->pc();
it.Advance();
@@ -837,14 +841,45 @@
void Logger::CodeMoveEvent(Address from, Address to) {
#ifdef ENABLE_LOGGING_AND_PROFILING
- static Address prev_to_ = NULL;
+ MoveEventInternal(CODE_MOVE_EVENT, from, to);
+#endif
+}
+
+
+void Logger::CodeDeleteEvent(Address from) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ DeleteEventInternal(CODE_DELETE_EVENT, from);
+#endif
+}
+
+
+void Logger::SnapshotPositionEvent(Address addr, int pos) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
+ LogMessageBuilder msg;
+ msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
+ msg.AppendAddress(addr);
+ msg.Append(",%d", pos);
+ if (FLAG_compress_log) {
+ ASSERT(compression_helper_ != NULL);
+ if (!compression_helper_->HandleMessage(&msg)) return;
+ }
+ msg.Append('\n');
+ msg.WriteToLogFile();
+#endif
+}
+
+
+void Logger::FunctionCreateEvent(JSFunction* function) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ static Address prev_code = NULL;
if (!Log::IsEnabled() || !FLAG_log_code) return;
LogMessageBuilder msg;
- msg.Append("%s,", log_events_[CODE_MOVE_EVENT]);
- msg.AppendAddress(from);
+ msg.Append("%s,", log_events_[FUNCTION_CREATION_EVENT]);
+ msg.AppendAddress(function->address());
msg.Append(',');
- msg.AppendAddress(to, prev_to_);
- prev_to_ = to;
+ msg.AppendAddress(function->code()->address(), prev_code);
+ prev_code = function->code()->address();
if (FLAG_compress_log) {
ASSERT(compression_helper_ != NULL);
if (!compression_helper_->HandleMessage(&msg)) return;
@@ -855,12 +890,32 @@
}
-void Logger::CodeDeleteEvent(Address from) {
+void Logger::FunctionMoveEvent(Address from, Address to) {
#ifdef ENABLE_LOGGING_AND_PROFILING
+ MoveEventInternal(FUNCTION_MOVE_EVENT, from, to);
+#endif
+}
+
+
+void Logger::FunctionDeleteEvent(Address from) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ DeleteEventInternal(FUNCTION_DELETE_EVENT, from);
+#endif
+}
+
+
+void Logger::MoveEventInternal(LogEventsAndTags event,
+ Address from,
+ Address to) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ static Address prev_to_ = NULL;
if (!Log::IsEnabled() || !FLAG_log_code) return;
LogMessageBuilder msg;
- msg.Append("%s,", log_events_[CODE_DELETE_EVENT]);
+ msg.Append("%s,", log_events_[event]);
msg.AppendAddress(from);
+ msg.Append(',');
+ msg.AppendAddress(to, prev_to_);
+ prev_to_ = to;
if (FLAG_compress_log) {
ASSERT(compression_helper_ != NULL);
if (!compression_helper_->HandleMessage(&msg)) return;
@@ -871,13 +926,12 @@
}
-void Logger::SnapshotPositionEvent(Address addr, int pos) {
+void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) {
#ifdef ENABLE_LOGGING_AND_PROFILING
- if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
+ if (!Log::IsEnabled() || !FLAG_log_code) return;
LogMessageBuilder msg;
- msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
- msg.AppendAddress(addr);
- msg.Append(",%d", pos);
+ msg.Append("%s,", log_events_[event]);
+ msg.AppendAddress(from);
if (FLAG_compress_log) {
ASSERT(compression_helper_ != NULL);
if (!compression_helper_->HandleMessage(&msg)) return;
@@ -1069,13 +1123,17 @@
void Logger::TickEvent(TickSample* sample, bool overflow) {
if (!Log::IsEnabled() || !FLAG_prof) return;
static Address prev_sp = NULL;
+ static Address prev_function = NULL;
LogMessageBuilder msg;
msg.Append("%s,", log_events_[TICK_EVENT]);
- Address prev_addr = reinterpret_cast<Address>(sample->pc);
+ Address prev_addr = sample->pc;
msg.AppendAddress(prev_addr);
msg.Append(',');
- msg.AppendAddress(reinterpret_cast<Address>(sample->sp), prev_sp);
- prev_sp = reinterpret_cast<Address>(sample->sp);
+ msg.AppendAddress(sample->sp, prev_sp);
+ prev_sp = sample->sp;
+ msg.Append(',');
+ msg.AppendAddress(sample->function, prev_function);
+ prev_function = sample->function;
msg.Append(",%d", static_cast<int>(sample->state));
if (overflow) {
msg.Append(",overflow");
@@ -1144,6 +1202,7 @@
LOG(UncheckedStringEvent("profiler", "resume"));
FLAG_log_code = true;
LogCompiledFunctions();
+ LogFunctionObjects();
LogAccessorCallbacks();
if (!FLAG_sliding_state_window) ticker_->Start();
}
@@ -1288,6 +1347,20 @@
DeleteArray(sfis);
}
+
+
+void Logger::LogFunctionObjects() {
+ AssertNoAllocation no_alloc;
+ HeapIterator iterator;
+ while (iterator.has_next()) {
+ HeapObject* obj = iterator.next();
+ ASSERT(obj != NULL);
+ if (!obj->IsJSFunction()) continue;
+ JSFunction* jsf = JSFunction::cast(obj);
+ if (!jsf->is_compiled()) continue;
+ LOG(FunctionCreateEvent(jsf));
+ }
+}
void Logger::LogAccessorCallbacks() {
=======================================
--- /branches/bleeding_edge/src/log.h Mon Jan 18 08:04:25 2010
+++ /branches/bleeding_edge/src/log.h Thu Jan 21 08:42:41 2010
@@ -116,6 +116,9 @@
V(CODE_CREATION_EVENT, "code-creation", "cc") \
V(CODE_MOVE_EVENT, "code-move", "cm") \
V(CODE_DELETE_EVENT, "code-delete", "cd") \
+ V(FUNCTION_CREATION_EVENT, "function-creation", "fc") \
+ V(FUNCTION_MOVE_EVENT, "function-move", "fm") \
+ V(FUNCTION_DELETE_EVENT, "function-delete", "fd") \
V(SNAPSHOT_POSITION_EVENT, "snapshot-pos", "sp") \
V(TICK_EVENT, "tick", "t") \
V(REPEAT_META_EVENT, "repeat", "r") \
@@ -224,6 +227,12 @@
static void CodeMoveEvent(Address from, Address to);
// Emits a code delete event.
static void CodeDeleteEvent(Address from);
+ // Emits a function object create event.
+ static void FunctionCreateEvent(JSFunction* function);
+ // Emits a function move event.
+ static void FunctionMoveEvent(Address from, Address to);
+ // Emits a function delete event.
+ static void FunctionDeleteEvent(Address from);
static void SnapshotPositionEvent(Address addr, int pos);
@@ -278,6 +287,8 @@
// Logs all compiled functions found in the heap.
static void LogCompiledFunctions();
+ // Logs all compiled JSFunction objects found in the heap.
+ static void LogFunctionObjects();
// Logs all accessor callbacks found in the heap.
static void LogAccessorCallbacks();
// Used for logging stubs found in the snapshot.
@@ -299,6 +310,15 @@
const char* name,
Address entry_point);
+ // Internal configurable move event.
+ static void MoveEventInternal(LogEventsAndTags event,
+ Address from,
+ Address to);
+
+ // Internal configurable move event.
+ static void DeleteEventInternal(LogEventsAndTags event,
+ Address from);
+
// Emits aliases for compressed messages.
static void LogAliases();
=======================================
--- /branches/bleeding_edge/src/mark-compact.cc Thu Jan 21 06:22:28 2010
+++ /branches/bleeding_edge/src/mark-compact.cc Thu Jan 21 08:42:41 2010
@@ -967,12 +967,6 @@
// Most non-live objects are ignored.
inline void IgnoreNonLiveObject(HeapObject* object) {}
-
-
-// A code deletion event is logged for non-live code objects.
-inline void LogNonLiveCodeObject(HeapObject* object) {
- if (object->IsCode()) LOG(CodeDeleteEvent(object->address()));
-}
// Function template that, given a range of addresses (eg, a semispace or a
@@ -1122,10 +1116,7 @@
is_previous_alive = true;
}
} else {
- if (object->IsCode()) {
- // Notify the logger that compiled code has been collected.
- LOG(CodeDeleteEvent(Code::cast(object)->address()));
- }
+ MarkCompactCollector::ReportDeleteIfNeeded(object);
if (is_previous_alive) { // Transition from live to free.
free_start = current;
is_previous_alive = false;
@@ -1212,7 +1203,7 @@
Heap::old_data_space());
EncodeForwardingAddressesInPagedSpace<MCAllocateFromCodeSpace,
- LogNonLiveCodeObject>(
+ ReportDeleteIfNeeded>(
Heap::code_space());
EncodeForwardingAddressesInPagedSpace<MCAllocateFromCellSpace,
@@ -1952,6 +1943,8 @@
Code::cast(copied_to)->Relocate(new_addr - old_addr);
// Notify the logger that compiled code has moved.
LOG(CodeMoveEvent(old_addr, new_addr));
+ } else if (copied_to->IsJSFunction()) {
+ LOG(FunctionMoveEvent(old_addr, new_addr));
}
return obj_size;
@@ -2003,5 +1996,16 @@
#endif
Heap::RebuildRSets();
}
+
+
+void MarkCompactCollector::ReportDeleteIfNeeded(HeapObject* obj) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ if (obj->IsCode()) {
+ LOG(CodeDeleteEvent(obj->address()));
+ } else if (obj->IsJSFunction()) {
+ LOG(FunctionDeleteEvent(obj->address()));
+ }
+#endif
+}
} } // namespace v8::internal
=======================================
--- /branches/bleeding_edge/src/mark-compact.h Tue Jan 12 07:16:23 2010
+++ /branches/bleeding_edge/src/mark-compact.h Thu Jan 21 08:42:41 2010
@@ -115,6 +115,9 @@
static bool in_use() { return state_ > PREPARE_GC; }
#endif
+ // Determine type of object and emit deletion log event.
+ static void ReportDeleteIfNeeded(HeapObject* obj);
+
private:
#ifdef DEBUG
enum CollectorState {
=======================================
--- /branches/bleeding_edge/src/platform-freebsd.cc Thu Dec 3 01:29:21 2009
+++ /branches/bleeding_edge/src/platform-freebsd.cc Thu Jan 21 08:42:41 2010
@@ -555,17 +555,17 @@
ucontext_t* ucontext = reinterpret_cast<ucontext_t*>(context);
mcontext_t& mcontext = ucontext->uc_mcontext;
#if V8_HOST_ARCH_IA32
- sample.pc = mcontext.mc_eip;
- sample.sp = mcontext.mc_esp;
- sample.fp = mcontext.mc_ebp;
+ sample.pc = reinterpret_cast<Address>(mcontext.mc_eip);
+ sample.sp = reinterpret_cast<Address>(mcontext.mc_esp);
+ sample.fp = reinterpret_cast<Address>(mcontext.mc_ebp);
#elif V8_HOST_ARCH_X64
- sample.pc = mcontext.mc_rip;
- sample.sp = mcontext.mc_rsp;
- sample.fp = mcontext.mc_rbp;
+ sample.pc = reinterpret_cast<Address>(mcontext.mc_rip);
+ sample.sp = reinterpret_cast<Address>(mcontext.mc_rsp);
+ sample.fp = reinterpret_cast<Address>(mcontext.mc_rbp);
#elif V8_HOST_ARCH_ARM
- sample.pc = mcontext.mc_r15;
- sample.sp = mcontext.mc_r13;
- sample.fp = mcontext.mc_r11;
+ sample.pc = reinterpret_cast<Address>(mcontext.mc_r15);
+ sample.sp = reinterpret_cast<Address>(mcontext.mc_r13);
+ sample.fp = reinterpret_cast<Address>(mcontext.mc_r11);
#endif
active_sampler_->SampleStack(&sample);
}
=======================================
--- /branches/bleeding_edge/src/platform-linux.cc Thu Dec 3 01:29:21 2009
+++ /branches/bleeding_edge/src/platform-linux.cc Thu Jan 21 08:42:41 2010
@@ -707,23 +707,23 @@
ucontext_t* ucontext = reinterpret_cast<ucontext_t*>(context);
mcontext_t& mcontext = ucontext->uc_mcontext;
#if V8_HOST_ARCH_IA32
- sample.pc = mcontext.gregs[REG_EIP];
- sample.sp = mcontext.gregs[REG_ESP];
- sample.fp = mcontext.gregs[REG_EBP];
+ sample.pc = reinterpret_cast<Address>(mcontext.gregs[REG_EIP]);
+ sample.sp = reinterpret_cast<Address>(mcontext.gregs[REG_ESP]);
+ sample.fp = reinterpret_cast<Address>(mcontext.gregs[REG_EBP]);
#elif V8_HOST_ARCH_X64
- sample.pc = mcontext.gregs[REG_RIP];
- sample.sp = mcontext.gregs[REG_RSP];
- sample.fp = mcontext.gregs[REG_RBP];
+ sample.pc = reinterpret_cast<Address>(mcontext.gregs[REG_RIP]);
+ sample.sp = reinterpret_cast<Address>(mcontext.gregs[REG_RSP]);
+ sample.fp = reinterpret_cast<Address>(mcontext.gregs[REG_RBP]);
#elif V8_HOST_ARCH_ARM
// An undefined macro evaluates to 0, so this applies to Android's Bionic
also.
#if (__GLIBC__ < 2 || (__GLIBC__ == 2 && __GLIBC_MINOR__ <= 3))
- sample.pc = mcontext.gregs[R15];
- sample.sp = mcontext.gregs[R13];
- sample.fp = mcontext.gregs[R11];
+ sample.pc = reinterpret_cast<Address>(mcontext.gregs[R15]);
+ sample.sp = reinterpret_cast<Address>(mcontext.gregs[R13]);
+ sample.fp = reinterpret_cast<Address>(mcontext.gregs[R11]);
#else
- sample.pc = mcontext.arm_pc;
- sample.sp = mcontext.arm_sp;
- sample.fp = mcontext.arm_fp;
+ sample.pc = reinterpret_cast<Address>(mcontext.arm_pc);
+ sample.sp = reinterpret_cast<Address>(mcontext.arm_sp);
+ sample.fp = reinterpret_cast<Address>(mcontext.arm_fp);
#endif
#endif
if (IsVmThread())
=======================================
--- /branches/bleeding_edge/src/platform-macos.cc Thu Dec 3 01:29:21 2009
+++ /branches/bleeding_edge/src/platform-macos.cc Thu Jan 21 08:42:41 2010
@@ -559,9 +559,9 @@
flavor,
reinterpret_cast<natural_t*>(&state),
&count) == KERN_SUCCESS) {
- sample.pc = state.REGISTER_FIELD(ip);
- sample.sp = state.REGISTER_FIELD(sp);
- sample.fp = state.REGISTER_FIELD(bp);
+ sample.pc = reinterpret_cast<Address>(state.REGISTER_FIELD(ip));
+ sample.sp = reinterpret_cast<Address>(state.REGISTER_FIELD(sp));
+ sample.fp = reinterpret_cast<Address>(state.REGISTER_FIELD(bp));
sampler_->SampleStack(&sample);
}
thread_resume(profiled_thread_);
=======================================
--- /branches/bleeding_edge/src/platform-win32.cc Fri Nov 13 04:32:57 2009
+++ /branches/bleeding_edge/src/platform-win32.cc Thu Jan 21 08:42:41 2010
@@ -1813,13 +1813,13 @@
context.ContextFlags = CONTEXT_FULL;
if (GetThreadContext(profiled_thread_, &context) != 0) {
#if V8_HOST_ARCH_X64
- sample.pc = context.Rip;
- sample.sp = context.Rsp;
- sample.fp = context.Rbp;
+ sample.pc = reinterpret_cast<Address>(context.Rip);
+ sample.sp = reinterpret_cast<Address>(context.Rsp);
+ sample.fp = reinterpret_cast<Address>(context.Rbp);
#else
- sample.pc = context.Eip;
- sample.sp = context.Esp;
- sample.fp = context.Ebp;
+ sample.pc = reinterpret_cast<Address>(context.Eip);
+ sample.sp = reinterpret_cast<Address>(context.Esp);
+ sample.fp = reinterpret_cast<Address>(context.Ebp);
#endif
sampler_->SampleStack(&sample);
}
=======================================
--- /branches/bleeding_edge/src/platform.h Fri Nov 13 04:32:57 2009
+++ /branches/bleeding_edge/src/platform.h Thu Jan 21 08:42:41 2010
@@ -506,11 +506,18 @@
// TickSample captures the information collected for each sample.
class TickSample {
public:
- TickSample() : pc(0), sp(0), fp(0), state(OTHER), frames_count(0) {}
- uintptr_t pc; // Instruction pointer.
- uintptr_t sp; // Stack pointer.
- uintptr_t fp; // Frame pointer.
- StateTag state; // The state of the VM.
+ TickSample()
+ : pc(NULL),
+ sp(NULL),
+ fp(NULL),
+ function(NULL),
+ state(OTHER),
+ frames_count(0) {}
+ Address pc; // Instruction pointer.
+ Address sp; // Stack pointer.
+ Address fp; // Frame pointer.
+ Address function; // The last called JS function.
+ StateTag state; // The state of the VM.
static const int kMaxFramesCount = 100;
EmbeddedVector<Address, kMaxFramesCount> stack; // Call stack.
int frames_count; // Number of captured frames.
=======================================
--- /branches/bleeding_edge/src/runtime.cc Wed Jan 20 06:43:12 2010
+++ /branches/bleeding_edge/src/runtime.cc Thu Jan 21 08:42:41 2010
@@ -4830,6 +4830,7 @@
CompileLazyShared(Handle<SharedFunctionInfo>(function->shared()),
CLEAR_EXCEPTION,
0);
+ LOG(FunctionCreateEvent(*function));
}
bool first_allocation = !function->has_initial_map();
=======================================
--- /branches/bleeding_edge/src/spaces.cc Thu Jan 14 06:46:31 2010
+++ /branches/bleeding_edge/src/spaces.cc Thu Jan 21 08:42:41 2010
@@ -2718,9 +2718,7 @@
}
// Free the chunk.
- if (object->IsCode()) {
- LOG(CodeDeleteEvent(object->address()));
- }
+ MarkCompactCollector::ReportDeleteIfNeeded(object);
size_ -= static_cast<int>(chunk_size);
page_count_--;
MemoryAllocator::FreeRawMemory(chunk_address, chunk_size);
=======================================
--- /branches/bleeding_edge/test/cctest/test-log-stack-tracer.cc Wed Nov 4
00:51:48 2009
+++ /branches/bleeding_edge/test/cctest/test-log-stack-tracer.cc Thu Jan 21
08:42:41 2010
@@ -47,10 +47,10 @@
static void DoTrace(Address fp) {
- trace_env.sample->fp = reinterpret_cast<uintptr_t>(fp);
+ trace_env.sample->fp = fp;
// sp is only used to define stack high bound
trace_env.sample->sp =
- reinterpret_cast<uintptr_t>(trace_env.sample) - 10240;
+ reinterpret_cast<Address>(trace_env.sample) - 10240;
StackTracer::Trace(trace_env.sample);
}
=======================================
--- /branches/bleeding_edge/test/cctest/test-log.cc Wed Nov 25 08:39:18 2009
+++ /branches/bleeding_edge/test/cctest/test-log.cc Thu Jan 21 08:42:41 2010
@@ -202,9 +202,9 @@
// Force compiler to generate new code by parametrizing source.
EmbeddedVector<char, 100> script_src;
i::OS::SNPrintF(script_src,
- "for (var i = 0; i < 1000; ++i) { "
- "(function(x) { return %d * x; })(i); }",
- log_pos);
+ "function f%d(x) { return %d * x; }"
+ "for (var i = 0; i < 10000; ++i) { f%d(i); }",
+ log_pos, log_pos, log_pos);
// Run code for 200 msecs to get some ticks.
const double end_time = i::OS::TimeCurrentMillis() + 200;
while (i::OS::TimeCurrentMillis() < end_time) {
@@ -228,6 +228,7 @@
log_pos += log_size;
// Check buffer contents.
buffer[log_size] = '\0';
+ printf("%s", buffer.start());
const char* tick = "\ntick,";
CHECK_NE(NULL, strstr(buffer.start(), code_creation));
const bool ticks_found = strstr(buffer.start(), tick) != NULL;
=======================================
--- /branches/bleeding_edge/test/mjsunit/tools/logreader.js Mon Aug 17
02:31:58 2009
+++ /branches/bleeding_edge/test/mjsunit/tools/logreader.js Thu Jan 21
08:42:41 2010
@@ -67,7 +67,7 @@
var reader = new devtools.profiler.LogReader({});
assertEquals([0x10000000, 0x10001000, 0xffff000, 0x10000000],
- reader.processStack(0x10000000, ['overflow',
+ reader.processStack(0x10000000, 0, ['overflow',
'+1000', '-2000', '+1000']));
})();
=======================================
--- /branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test.log Wed
Jul 8 23:39:38 2009
+++ /branches/bleeding_edge/test/mjsunit/tools/tickprocessor-test.log Thu
Jan 21 08:42:41 2010
@@ -6,19 +6,20 @@
code-creation,Script,0xf541cd80,736,"exp.js"
code-creation,Stub,0xf541d0e0,47,"RuntimeStub_Math_exp"
code-creation,LazyCompile,0xf541d120,145,"exp native math.js:41"
+function-creation,0xf441d280,0xf541d120
code-creation,LoadIC,0xf541d280,117,"j"
code-creation,LoadIC,0xf541d360,63,"i"
-tick,0x80f82d1,0xffdfe880,0,0xf541ce5c
-tick,0x80f89a1,0xffdfecf0,0,0xf541ce5c
-tick,0x8123b5c,0xffdff1a0,0,0xf541d1a1,0xf541ceea
-tick,0x8123b65,0xffdff1a0,0,0xf541d1a1,0xf541ceea
-tick,0xf541d2be,0xffdff1e4,0
-tick,0xf541d320,0xffdff1dc,0
-tick,0xf541d384,0xffdff1d8,0
-tick,0xf7db94da,0xffdff0ec,0,0xf541d1a1,0xf541ceea
-tick,0xf7db951c,0xffdff0f0,0,0xf541d1a1,0xf541ceea
-tick,0xf7dbc508,0xffdff14c,0,0xf541d1a1,0xf541ceea
-tick,0xf7dbff21,0xffdff198,0,0xf541d1a1,0xf541ceea
-tick,0xf7edec90,0xffdff0ec,0,0xf541d1a1,0xf541ceea
-tick,0xffffe402,0xffdff488,0
+tick,0x80f82d1,0xffdfe880,0,0,0xf541ce5c
+tick,0x80f89a1,0xffdfecf0,0,0,0xf541ce5c
+tick,0x8123b5c,0xffdff1a0,0,0,0xf541d1a1,0xf541ceea
+tick,0x8123b65,0xffdff1a0,0,0,0xf541d1a1,0xf541ceea
+tick,0xf541d2be,0xffdff1e4,0,0
+tick,0xf541d320,0xffdff1dc,0,0
+tick,0xf541d384,0xffdff1d8,0,0
+tick,0xf7db94da,0xffdff0ec,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7db951c,0xffdff0f0,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7dbc508,0xffdff14c,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7dbff21,0xffdff198,0,0,0xf541d1a1,0xf541ceea
+tick,0xf7edec90,0xffdff0ec,0,0,0xf541d1a1,0xf541ceea
+tick,0xffffe402,0xffdff488,0,0
profiler,"end"
=======================================
--- /branches/bleeding_edge/test/mjsunit/tools/tickprocessor.js Mon Aug 17
06:45:03 2009
+++ /branches/bleeding_edge/test/mjsunit/tools/tickprocessor.js Thu Jan 21
08:42:41 2010
@@ -334,7 +334,7 @@
print = function(str) {
var strSplit = str.split('\n');
for (var i = 0; i < strSplit.length; ++i) {
- s = strSplit[i];
+ var s = strSplit[i];
realOut.push(s);
if (outputPos < expectedOut.length) {
if (expectedOut[outputPos] != s) {
@@ -400,7 +400,10 @@
'tickprocessor-test.log', 'tickprocessor-test.ignore-unknown'],
'GcState': [
false, false, TickProcessor.VmStates.GC,
- 'tickprocessor-test.log', 'tickprocessor-test.gc-state']
+ 'tickprocessor-test.log', 'tickprocessor-test.gc-state'],
+ 'FunctionInfo': [
+ false, false, null,
+ 'tickprocessor-test-func-info.log', 'tickprocessor-test.func-info']
};
for (var testName in testData) {
print('=== testProcessing-' + testName + ' ===');
=======================================
--- /branches/bleeding_edge/tools/codemap.js Wed Nov 25 08:39:18 2009
+++ /branches/bleeding_edge/tools/codemap.js Thu Jan 21 08:42:41 2010
@@ -195,6 +195,18 @@
};
+/**
+ * Returns a dynamic code entry using its starting address.
+ *
+ * @param {number} addr Address.
+ */
+devtools.profiler.CodeMap.prototype.findDynamicEntryByStartAddress =
+ function(addr) {
+ var node = this.dynamics_.find(addr);
+ return node ? node.value : null;
+};
+
+
/**
* Returns an array of all dynamic code entries.
*/
=======================================
--- /branches/bleeding_edge/tools/logreader.js Mon Aug 17 02:31:58 2009
+++ /branches/bleeding_edge/tools/logreader.js Thu Jan 21 08:42:41 2010
@@ -139,11 +139,12 @@
* Processes stack record.
*
* @param {number} pc Program counter.
+ * @param {number} func JS Function.
* @param {Array.<string>} stack String representation of a stack.
* @return {Array.<number>} Processed stack.
*/
-devtools.profiler.LogReader.prototype.processStack = function(pc, stack) {
- var fullStack = [pc];
+devtools.profiler.LogReader.prototype.processStack = function(pc, func,
stack) {
+ var fullStack = func ? [pc, func] : [pc];
var prevFrame = pc;
for (var i = 0, n = stack.length; i < n; ++i) {
var frame = stack[i];
=======================================
--- /branches/bleeding_edge/tools/profile.js Mon Jan 18 08:04:25 2010
+++ /branches/bleeding_edge/tools/profile.js Thu Jan 21 08:42:41 2010
@@ -43,6 +43,11 @@
this.bottomUpTree_ = new devtools.profiler.CallTree();
};
+/**
+ * Version of profiler log.
+ */
+devtools.profiler.Profile.VERSION = 2;
+
/**
* Returns whether a function with the specified name must be skipped.
@@ -133,6 +138,21 @@
};
+/**
+ * Creates an alias entry for a code entry.
+ *
+ * @param {number} aliasAddr Alias address.
+ * @param {number} addr Code entry address.
+ */
+devtools.profiler.Profile.prototype.addCodeAlias = function(
+ aliasAddr, addr) {
+ var entry = this.codeMap_.findDynamicEntryByStartAddress(addr);
+ if (entry) {
+ this.codeMap_.addCode(aliasAddr, entry);
+ }
+};
+
+
/**
* Reports about moving of a dynamic code entry.
*
@@ -162,6 +182,31 @@
};
+/**
+ * Reports about moving of a dynamic code entry.
+ *
+ * @param {number} from Current code entry address.
+ * @param {number} to New code entry address.
+ */
+devtools.profiler.Profile.prototype.safeMoveDynamicCode = function(from,
to) {
+ if (this.codeMap_.findDynamicEntryByStartAddress(from)) {
+ this.codeMap_.moveCode(from, to);
+ }
+};
+
+
+/**
+ * Reports about deletion of a dynamic code entry.
+ *
+ * @param {number} start Starting address.
+ */
+devtools.profiler.Profile.prototype.safeDeleteDynamicCode =
function(start) {
+ if (this.codeMap_.findDynamicEntryByStartAddress(start)) {
+ this.codeMap_.deleteCode(start);
+ }
+};
+
+
/**
* Retrieves a code entry by an address.
*
@@ -362,6 +407,13 @@
};
+devtools.profiler.Profile.DynamicCodeEntry.prototype.isJSFunction =
function() {
+ return this.type == "Function" ||
+ this.type == "LazyCompile" ||
+ this.type == "Script";
+};
+
+
/**
* Constructs a call graph.
*
=======================================
--- /branches/bleeding_edge/tools/tickprocessor.js Mon Jan 18 08:04:25 2010
+++ /branches/bleeding_edge/tools/tickprocessor.js Thu Jan 21 08:42:41 2010
@@ -137,10 +137,19 @@
processor: this.processCodeMove, backrefs: true },
'code-delete': { parsers: [this.createAddressParser('code')],
processor: this.processCodeDelete, backrefs: true },
+ 'function-creation': { parsers: [this.createAddressParser('code'),
+ this.createAddressParser('function-obj')],
+ processor: this.processFunctionCreation, backrefs: true },
+ 'function-move': { parsers: [this.createAddressParser('code'),
+ this.createAddressParser('code-move-to')],
+ processor: this.processFunctionMove, backrefs: true },
+ 'function-delete': { parsers: [this.createAddressParser('code')],
+ processor: this.processFunctionDelete, backrefs: true },
'snapshot-pos': { parsers: [this.createAddressParser('code'),
parseInt],
processor: this.processSnapshotPosition, backrefs: true },
'tick': { parsers: [this.createAddressParser('code'),
- this.createAddressParser('stack'), parseInt, 'var-args'],
+ this.createAddressParser('stack'),
+ this.createAddressParser('func'), parseInt, 'var-args'],
processor: this.processTick, backrefs: true },
'heap-sample-begin': { parsers: [null, null, parseInt],
processor: this.processHeapSampleBegin },
@@ -287,6 +296,22 @@
};
+TickProcessor.prototype.processFunctionCreation = function(
+ functionAddr, codeAddr) {
+ this.profile_.addCodeAlias(functionAddr, codeAddr);
+};
+
+
+TickProcessor.prototype.processFunctionMove = function(from, to) {
+ this.profile_.safeMoveDynamicCode(from, to);
+};
+
+
+TickProcessor.prototype.processFunctionDelete = function(start) {
+ this.profile_.safeDeleteDynamicCode(start);
+};
+
+
TickProcessor.prototype.processSnapshotPosition = function(addr, pos) {
if (this.snapshotLogProcessor_) {
this.deserializedEntriesNames_[addr] =
@@ -300,7 +325,7 @@
};
-TickProcessor.prototype.processTick = function(pc, sp, vmState, stack) {
+TickProcessor.prototype.processTick = function(pc, sp, func, vmState,
stack) {
this.ticks_.total++;
if (vmState == TickProcessor.VmStates.GC) this.ticks_.gc++;
if (!this.includeTick(vmState)) {
@@ -308,7 +333,19 @@
return;
}
- this.profile_.recordTick(this.processStack(pc, stack));
+ if (func) {
+ var funcEntry = this.profile_.findEntry(func);
+ if (!funcEntry || !funcEntry.isJSFunction |
| !funcEntry.isJSFunction()) {
+ func = 0;
+ } else {
+ var currEntry = this.profile_.findEntry(pc);
+ if (!currEntry || !currEntry.isJSFunction ||
currEntry.isJSFunction()) {
+ func = 0;
+ }
+ }
+ }
+
+ this.profile_.recordTick(this.processStack(pc, func, stack));
};
@@ -341,7 +378,7 @@
if (stack.length == 0) return;
var first = stack.shift();
var processedStack =
- this.profile_.resolveAndFilterFuncs_(this.processStack(first,
stack));
+ this.profile_.resolveAndFilterFuncs_(this.processStack(first, 0,
stack));
processedStack.unshift(constructor);
this.currentProducerProfile_.addPath(processedStack);
};
=======================================
--- /branches/bleeding_edge/tools/tickprocessor.py Mon Apr 27 06:50:42 2009
+++ /branches/bleeding_edge/tools/tickprocessor.py Thu Jan 21 08:42:41 2010
@@ -59,6 +59,8 @@
def IsICEntry(self):
return False
+ def IsJSFunction(self):
+ return False
class SharedLibraryEntry(CodeEntry):
@@ -124,6 +126,8 @@
return self.type in ('CallIC', 'LoadIC', 'StoreIC') or \
(self.type == 'Builtin' and self.builtin_ic_re.match(self.name))
+ def IsJSFunction(self):
+ return self.type in ('Function', 'LazyCompile', 'Script')
class CodeRegion(object):
@@ -212,13 +216,19 @@
for row in logreader:
row_num += 1
if row[0] == 'tick':
- self.ProcessTick(int(row[1], 16), int(row[2], 16),
int(row[3]), self.PreprocessStack(row[4:]))
+ self.ProcessTick(int(row[1], 16), int(row[2], 16), int(row[3],
16), int(row[4]), self.PreprocessStack(row[5:]))
elif row[0] == 'code-creation':
self.ProcessCodeCreation(row[1], int(row[2], 16), int(row[3]),
row[4])
elif row[0] == 'code-move':
self.ProcessCodeMove(int(row[1], 16), int(row[2], 16))
elif row[0] == 'code-delete':
self.ProcessCodeDelete(int(row[1], 16))
+ elif row[0] == 'function-creation':
+ self.ProcessFunctionCreation(int(row[1], 16), int(row[2], 16))
+ elif row[0] == 'function-move':
+ self.ProcessFunctionMove(int(row[1], 16), int(row[2], 16))
+ elif row[0] == 'function-delete':
+ self.ProcessFunctionDelete(int(row[1], 16))
elif row[0] == 'shared-library':
self.AddSharedLibraryEntry(row[1], int(row[2], 16),
int(row[3], 16))
self.ParseVMSymbols(row[1], int(row[2], 16), int(row[3], 16))
@@ -275,6 +285,27 @@
except splaytree.KeyNotFoundError:
print('Code delete event for unknown code: 0x%x' % from_addr)
+ def ProcessFunctionCreation(self, func_addr, code_addr):
+ js_entry_node = self.js_entries.Find(code_addr)
+ if js_entry_node:
+ js_entry = js_entry_node.value
+ self.js_entries.Insert(func_addr, JSCodeEntry(func_addr,
js_entry.name, js_entry.type, 1, None))
+
+ def ProcessFunctionMove(self, from_addr, to_addr):
+ try:
+ removed_node = self.js_entries.Remove(from_addr)
+ removed_node.value.SetStartAddress(to_addr);
+ self.js_entries.Insert(to_addr, removed_node.value)
+ except splaytree.KeyNotFoundError:
+ return
+
+ def ProcessFunctionDelete(self, from_addr):
+ try:
+ removed_node = self.js_entries.Remove(from_addr)
+ self.deleted_code.append(removed_node.value)
+ except splaytree.KeyNotFoundError:
+ return
+
def ProcessBeginCodeRegion(self, id, assm, start, name):
if not assm in self.pending_assemblers:
self.pending_assemblers[assm] = Assembler()
@@ -320,7 +351,7 @@
result.append(entry.ToString())
return result
- def ProcessTick(self, pc, sp, state, stack):
+ def ProcessTick(self, pc, sp, func, state, stack):
if state == VMStates['GC']:
self.number_of_gc_ticks += 1
if not self.IncludeTick(pc, sp, state):
@@ -337,11 +368,16 @@
if len(stack) > 0:
caller_pc = stack.pop(0)
self.total_number_of_ticks -= 1
- self.ProcessTick(caller_pc, sp, state, stack)
+ self.ProcessTick(caller_pc, sp, func, state, stack)
else:
self.unaccounted_number_of_ticks += 1
else:
- entry.Tick(pc, self.ProcessStack(stack))
+ processed_stack = self.ProcessStack(stack)
+ if not entry.IsSharedLibraryEntry() and not entry.IsJSFunction():
+ func_entry_node = self.js_entries.Find(func)
+ if func_entry_node and func_entry_node.value.IsJSFunction():
+ processed_stack.insert(0, func_entry_node.value.ToString())
+ entry.Tick(pc, processed_stack)
if self.call_graph_json:
self.AddToPackedStacks(pc, stack)
--
v8-dev mailing list
[email protected]
http://groups.google.com/group/v8-dev
