From 6fb6d9b62f3fe2344b40d0e435bed7fa9f880ebf Mon Sep 17 00:00:00 2001 From: Brice Dutheil Date: Thu, 20 Mar 2025 16:59:58 +0100 Subject: [PATCH 1/3] Add profiler counters for time spent in stack unwinding --- ddprof-lib/src/main/cpp/counters.h | 5 +- .../src/main/cpp/stackFrame_aarch64.cpp | 66 ++++++++++++++++ ddprof-lib/src/main/cpp/stackFrame_arm.cpp | 35 +++++++++ ddprof-lib/src/main/cpp/stackFrame_i386.cpp | 47 +++++++++++ ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp | 18 +++++ ddprof-lib/src/main/cpp/stackFrame_x64.cpp | 78 ++++++++++++++++++- 6 files changed, 247 insertions(+), 2 deletions(-) diff --git a/ddprof-lib/src/main/cpp/counters.h b/ddprof-lib/src/main/cpp/counters.h index b6e28b12f..af8e0fa06 100644 --- a/ddprof-lib/src/main/cpp/counters.h +++ b/ddprof-lib/src/main/cpp/counters.h @@ -59,7 +59,10 @@ X(AGCT_NOT_JAVA, "agct_not_java") \ X(AGCT_NATIVE_NO_JAVA_CONTEXT, "agct_native_no_java_context") \ X(AGCT_BLOCKED_IN_VM, "agct_blocked_in_vm") \ - X(SKIPPED_WALLCLOCK_UNWINDS, "skipped_wallclock_unwinds") + X(SKIPPED_WALLCLOCK_UNWINDS, "skipped_wallclock_unwinds") \ + X(UNWINDING_STUB_TIME, "unwinding_stub_time") \ + X(UNWINDING_COMPILED_TIME, "unwinding_compiled_time") \ + X(UNWINDING_ATOMIC_STUB_TIME, "unwinding_atomic_stub_time") #define X_ENUM(a, b) a, typedef enum CounterId : int { DD_COUNTER_TABLE(X_ENUM) DD_NUM_COUNTERS diff --git a/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp b/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp index 58d1ae475..ac23d6584 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp @@ -23,6 +23,9 @@ #include #include +#include "counters.h" +#include "tsc.h" + #ifdef __APPLE__ #define REG(l, m) _ucontext->uc_mcontext->__ss.__##m #else @@ -57,6 +60,7 @@ void StackFrame::ret() { pc() = link(); } bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xd65f03c0 || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || @@ -67,6 +71,12 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, strcmp(name, "atomic entry points") == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = link(); + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } else if (strcmp(name, "forward_copy_longs") == 0 || strcmp(name, "backward_copy_longs") == 0 @@ -83,6 +93,12 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, // When cstack=vm, unwind stub frames one by one pc = link(); } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } else if (entry != NULL && entry[0] == 0xa9bf7bfd) { // The stub begins with @@ -91,11 +107,23 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, if (ip == entry + 1) { sp += 16; pc = ((uintptr_t *)sp)[-1]; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } else if (entry[1] == 0x910003fd && withinCurrentStack(fp)) { sp = fp + 16; fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } } else if (strncmp(name, "indexof_linear_", 15) == 0 && @@ -117,6 +145,7 @@ static inline bool isEntryBarrier(instruction_t *ip) { bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if ((*ip & 0xffe07fff) == 0xa9007bfd) { @@ -125,34 +154,71 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, unsigned int offset = (*ip >> 12) & 0x1f8; sp += offset + 16; pc = link(); + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } } else if (ip > entry && ip[0] == 0x910003fd && ip[-1] == 0xa9bf7bfd) { // stp x29, x30, [sp, #-16]! // mov x29, sp sp += 16; pc = ((uintptr_t *)sp)[-1]; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } } else if (ip > entry + 3 && !nm->isFrameCompleteAt(ip) && (isEntryBarrier(ip) || isEntryBarrier(ip + 1))) { // Frame should be complete at this point sp += nm->frameSize() * sizeof(void *); fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } } else { // Just try pc = link(); } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } bool StackFrame::unwindAtomicStub(const void*& pc) { // VM threads may call generated atomic stubs, which are not normally walkable + const u64 startTime = TSC::ticks(); const void* lr = (const void*)link(); if (VMStructs::libjvm()->contains(lr)) { NMethod* nm = CodeHeap::findNMethod(pc); if (nm != NULL && strncmp(nm->name(), "Stub", 4) == 0) { pc = lr; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_ATOMIC_STUB_TIME, duration); + } return true; } } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_ATOMIC_STUB_TIME, duration); + } return false; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_arm.cpp b/ddprof-lib/src/main/cpp/stackFrame_arm.cpp index 5f72491eb..b9f0f7727 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_arm.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_arm.cpp @@ -21,6 +21,9 @@ #include #include +#include "counters.h" +#include "tsc.h" + uintptr_t &StackFrame::pc() { return (uintptr_t &)_ucontext->uc_mcontext.arm_pc; } @@ -74,18 +77,32 @@ void StackFrame::ret() { pc() = link(); } bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xe12fff1e || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = link(); + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } + + const u64 endTime = TSC::ticks(); + u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return false; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if (ip > entry && ip <= entry + 4 && (*ip & 0xffffff00) == 0xe24dd000) { @@ -95,6 +112,12 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1]; sp += 8; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } else if (*ip == 0xe8bd4800) { // add sp, sp, #offs @@ -102,9 +125,21 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1]; sp += 8; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } pc = link(); + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_i386.cpp b/ddprof-lib/src/main/cpp/stackFrame_i386.cpp index fdf4159a6..0780be884 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_i386.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_i386.cpp @@ -21,6 +21,9 @@ #include #include +#include "counters.h" +#include "tsc.h" + uintptr_t &StackFrame::pc() { return (uintptr_t &)_ucontext->uc_mcontext.gregs[REG_EIP]; } @@ -68,12 +71,19 @@ void StackFrame::ret() { bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xc3 || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = *(uintptr_t *)sp; sp += 4; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } else if (entry != NULL && entry[0] == 0x55 && entry[1] == 0x8b && entry[2] == 0xec) { @@ -83,19 +93,38 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, if (ip == entry + 1) { pc = ((uintptr_t *)sp)[1]; sp += 8; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } else if (withinCurrentStack(fp)) { sp = fp + 8; fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return false; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if (ip <= entry || *ip == 0xc3 // ret @@ -104,14 +133,32 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, { pc = *(uintptr_t *)sp; sp += 4; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } else if (*ip == 0x5d) { // pop ebp fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1]; sp += 8; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return false; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp b/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp index a06c0c0e1..712d93be5 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp @@ -22,6 +22,9 @@ #include #include +#include "counters.h" +#include "tsc.h" + uintptr_t &StackFrame::pc() { return (uintptr_t &)_ucontext->uc_mcontext.regs->nip; } @@ -112,12 +115,21 @@ static inline bool inC2PrologueCrit(uintptr_t pc) { bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); pc = link(); + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); + // On PPC there is a valid back link to the previous frame at all times. The // callee stores the return address in the caller's frame before it constructs // its own frame. After it has destroyed its frame it restores the link @@ -140,6 +152,12 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, pc = link(); } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_x64.cpp b/ddprof-lib/src/main/cpp/stackFrame_x64.cpp index 40fcb8cfa..1a6241294 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_x64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_x64.cpp @@ -22,6 +22,9 @@ #include #include +#include "counters.h" +#include "tsc.h" + #ifdef __APPLE__ #define REG(l, m) _ucontext->uc_mcontext->__ss.__##m #else @@ -62,19 +65,36 @@ void StackFrame::ret() { bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xc3 || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = ((uintptr_t *)sp)[0] - 1; sp += 8; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } if (entry == nullptr) { + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return false; } if (reinterpret_cast(entry) % alignof(unsigned int) != 0) { + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return false; } if (*(unsigned int *)entry == 0xec8b4855) { @@ -84,19 +104,38 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, if (ip == entry + 1) { pc = ((uintptr_t *)sp)[1] - 1; sp += 16; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } else if (withinCurrentStack(fp)) { sp = fp + 16; fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1] - 1; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return true; } } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_STUB_TIME, duration); + } return false; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { + const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if (ip <= entry || *ip == 0xc3 // ret @@ -109,23 +148,48 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, // otherwise it may be attributed to a wrong bytecode pc = ((uintptr_t *)sp)[0] - 1; sp += 8; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) + { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } else if (*ip == 0x5d) { // pop rbp fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1] - 1; sp += 16; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } else if (ip <= entry + 15 && ((uintptr_t)ip & 0xfff) && ip[-1] == 0x55) { // push rbp pc = ((uintptr_t *)sp)[1] - 1; sp += 16; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } else if (ip <= entry + 7 && ip[0] == 0x48 && ip[1] == 0x89 && ip[2] == 0x6c && ip[3] == 0x24) { // mov [rsp + #off], rbp sp += ip[4] + 16; pc = ((uintptr_t *)sp)[-1] - 1; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } else if ((ip[0] == 0x41 && ip[1] == 0x81 && ip[2] == 0x7f && *(u32 *)(ip + 4) == 1) || @@ -136,8 +200,20 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, sp += nm->frameSize() * sizeof(void *); fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return true; } + + const u64 endTime = TSC::ticks(); + const u64 duration = TSC::ticks_to_millis(endTime - startTime); + if (duration > 1) { + Counters::increment(UNWINDING_COMPILED_TIME, duration); + } return false; } From 3dde0b5d3ac06536f91821fd39bad447dad609b5 Mon Sep 17 00:00:00 2001 From: Brice Dutheil Date: Wed, 26 Mar 2025 22:23:31 +0100 Subject: [PATCH 2/3] Unify unwinding counters to single counters --- ddprof-lib/src/main/cpp/counters.h | 4 +--- .../src/main/cpp/stackFrame_aarch64.cpp | 20 ++++++++-------- ddprof-lib/src/main/cpp/stackFrame_arm.cpp | 10 ++++---- ddprof-lib/src/main/cpp/stackFrame_i386.cpp | 14 +++++------ ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp | 4 ++-- ddprof-lib/src/main/cpp/stackFrame_x64.cpp | 24 +++++++++---------- 6 files changed, 37 insertions(+), 39 deletions(-) diff --git a/ddprof-lib/src/main/cpp/counters.h b/ddprof-lib/src/main/cpp/counters.h index af8e0fa06..d92c9e8d5 100644 --- a/ddprof-lib/src/main/cpp/counters.h +++ b/ddprof-lib/src/main/cpp/counters.h @@ -60,9 +60,7 @@ X(AGCT_NATIVE_NO_JAVA_CONTEXT, "agct_native_no_java_context") \ X(AGCT_BLOCKED_IN_VM, "agct_blocked_in_vm") \ X(SKIPPED_WALLCLOCK_UNWINDS, "skipped_wallclock_unwinds") \ - X(UNWINDING_STUB_TIME, "unwinding_stub_time") \ - X(UNWINDING_COMPILED_TIME, "unwinding_compiled_time") \ - X(UNWINDING_ATOMIC_STUB_TIME, "unwinding_atomic_stub_time") + X(UNWINDING_TIME, "unwinding_time") #define X_ENUM(a, b) a, typedef enum CounterId : int { DD_COUNTER_TABLE(X_ENUM) DD_NUM_COUNTERS diff --git a/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp b/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp index ac23d6584..761ba5d0e 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp @@ -75,7 +75,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (strcmp(name, "forward_copy_longs") == 0 || @@ -97,7 +97,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (entry != NULL && entry[0] == 0xa9bf7bfd) { @@ -111,7 +111,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (entry[1] == 0x910003fd && withinCurrentStack(fp)) { @@ -122,7 +122,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -158,7 +158,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } } else if (ip > entry && ip[0] == 0x910003fd && ip[-1] == 0xa9bf7bfd) { // stp x29, x30, [sp, #-16]! @@ -169,7 +169,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } } else if (ip > entry + 3 && !nm->isFrameCompleteAt(ip) && (isEntryBarrier(ip) || isEntryBarrier(ip + 1))) { @@ -181,7 +181,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } } else { // Just try @@ -191,7 +191,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -208,7 +208,7 @@ bool StackFrame::unwindAtomicStub(const void*& pc) { const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_ATOMIC_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -217,7 +217,7 @@ bool StackFrame::unwindAtomicStub(const void*& pc) { const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_ATOMIC_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_arm.cpp b/ddprof-lib/src/main/cpp/stackFrame_arm.cpp index b9f0f7727..755750720 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_arm.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_arm.cpp @@ -87,7 +87,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -95,7 +95,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } @@ -116,7 +116,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (*ip == 0xe8bd4800) { @@ -129,7 +129,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -138,7 +138,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_i386.cpp b/ddprof-lib/src/main/cpp/stackFrame_i386.cpp index 0780be884..5279055a9 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_i386.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_i386.cpp @@ -82,7 +82,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (entry != NULL && entry[0] == 0x55 && entry[1] == 0x8b && @@ -97,7 +97,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (withinCurrentStack(fp)) { @@ -108,7 +108,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -117,7 +117,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } @@ -137,7 +137,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (*ip == 0x5d) { @@ -149,7 +149,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -157,7 +157,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp b/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp index 712d93be5..49b84527b 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp @@ -121,7 +121,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -156,7 +156,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_x64.cpp b/ddprof-lib/src/main/cpp/stackFrame_x64.cpp index 1a6241294..049f53449 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_x64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_x64.cpp @@ -76,7 +76,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -84,7 +84,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } @@ -93,7 +93,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } @@ -108,7 +108,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (withinCurrentStack(fp)) { @@ -119,7 +119,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -128,7 +128,7 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_STUB_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } @@ -153,7 +153,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (*ip == 0x5d) { @@ -165,7 +165,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (ip <= entry + 15 && ((uintptr_t)ip & 0xfff) && ip[-1] == 0x55) { @@ -176,7 +176,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if (ip <= entry + 7 && ip[0] == 0x48 && ip[1] == 0x89 && @@ -188,7 +188,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } else if ((ip[0] == 0x41 && ip[1] == 0x81 && ip[2] == 0x7f && @@ -204,7 +204,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return true; } @@ -212,7 +212,7 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, const u64 endTime = TSC::ticks(); const u64 duration = TSC::ticks_to_millis(endTime - startTime); if (duration > 1) { - Counters::increment(UNWINDING_COMPILED_TIME, duration); + Counters::increment(UNWINDING_TIME, duration); } return false; } From e0a1ef1b24649b5cd9025427fd6aa970debb9002 Mon Sep 17 00:00:00 2001 From: Jaroslav Bachorik Date: Wed, 9 Apr 2025 13:56:26 +0200 Subject: [PATCH 3/3] Use single-entry for measuring unwinding costs --- ddprof-lib/src/main/cpp/counters.h | 3 +- ddprof-lib/src/main/cpp/profiler.cpp | 16 ++++ .../src/main/cpp/stackFrame_aarch64.cpp | 66 ---------------- ddprof-lib/src/main/cpp/stackFrame_arm.cpp | 35 --------- ddprof-lib/src/main/cpp/stackFrame_i386.cpp | 47 ----------- ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp | 18 ----- ddprof-lib/src/main/cpp/stackFrame_x64.cpp | 77 ------------------- ddprof-lib/src/main/cpp/stackWalker.cpp | 1 - 8 files changed, 18 insertions(+), 245 deletions(-) diff --git a/ddprof-lib/src/main/cpp/counters.h b/ddprof-lib/src/main/cpp/counters.h index d92c9e8d5..e1672a6b0 100644 --- a/ddprof-lib/src/main/cpp/counters.h +++ b/ddprof-lib/src/main/cpp/counters.h @@ -60,7 +60,8 @@ X(AGCT_NATIVE_NO_JAVA_CONTEXT, "agct_native_no_java_context") \ X(AGCT_BLOCKED_IN_VM, "agct_blocked_in_vm") \ X(SKIPPED_WALLCLOCK_UNWINDS, "skipped_wallclock_unwinds") \ - X(UNWINDING_TIME, "unwinding_time") + X(UNWINDING_TIME_ASYNC, "unwinding_ticks_async") \ + X(UNWINDING_TIME_JVMTI, "unwinding_ticks_jvmti") #define X_ENUM(a, b) a, typedef enum CounterId : int { DD_COUNTER_TABLE(X_ENUM) DD_NUM_COUNTERS diff --git a/ddprof-lib/src/main/cpp/profiler.cpp b/ddprof-lib/src/main/cpp/profiler.cpp index 005e2f160..4bfd3baeb 100644 --- a/ddprof-lib/src/main/cpp/profiler.cpp +++ b/ddprof-lib/src/main/cpp/profiler.cpp @@ -23,6 +23,7 @@ #include "stackWalker.h" #include "symbols.h" #include "thread.h" +#include "tsc.h" #include "vmStructs.h" #include "wallClock.h" #include @@ -600,6 +601,7 @@ u32 Profiler::recordJVMTISample(u64 counter, int tid, jthread thread, jint event } u32 call_trace_id = 0; if (!_omit_stacktraces) { + u64 startTime = TSC::ticks(); ASGCT_CallFrame *frames = _calltrace_buffer[lock_index]->_asgct_frames; jvmtiFrameInfo *jvmti_frames = _calltrace_buffer[lock_index]->_jvmti_frames; @@ -619,6 +621,10 @@ u32 Profiler::recordJVMTISample(u64 counter, int tid, jthread thread, jint event } call_trace_id = _call_trace_storage.put(num_frames, frames, false, counter); + u64 duration = TSC::ticks() - startTime; + if (duration > 0) { + Counters::increment(UNWINDING_TIME_JVMTI, duration); // increment the JVMTI specific counter + } } if (!deferred) { _jfr.recordEvent(lock_index, tid, call_trace_id, event_type, event); @@ -670,6 +676,7 @@ void Profiler::recordSample(void *ucontext, u64 counter, int tid, // record a null stacktrace we can skip the unwind if we've got a // call_trace_id determined to be reusable at a higher level if (!_omit_stacktraces && call_trace_id == 0) { + u64 startTime = TSC::ticks(); ASGCT_CallFrame *frames = _calltrace_buffer[lock_index]->_asgct_frames; int num_frames = 0; @@ -716,6 +723,10 @@ void Profiler::recordSample(void *ucontext, u64 counter, int tid, if (thread != nullptr) { thread->recordCallTraceId(call_trace_id); } + u64 duration = TSC::ticks() - startTime; + if (duration > 0) { + Counters::increment(UNWINDING_TIME_ASYNC, duration); // increment the async specific counter + } } _jfr.recordEvent(lock_index, tid, call_trace_id, event_type, event); @@ -1360,6 +1371,11 @@ Error Profiler::dump(const char *path, const int length) { _thread_info.clearAll(thread_ids); _thread_info.reportCounters(); + + // reset unwinding counters + Counters::set(UNWINDING_TIME_ASYNC, 0); + Counters::set(UNWINDING_TIME_JVMTI, 0); + return err; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp b/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp index 761ba5d0e..58d1ae475 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_aarch64.cpp @@ -23,9 +23,6 @@ #include #include -#include "counters.h" -#include "tsc.h" - #ifdef __APPLE__ #define REG(l, m) _ucontext->uc_mcontext->__ss.__##m #else @@ -60,7 +57,6 @@ void StackFrame::ret() { pc() = link(); } bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xd65f03c0 || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || @@ -71,12 +67,6 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, strcmp(name, "atomic entry points") == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = link(); - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (strcmp(name, "forward_copy_longs") == 0 || strcmp(name, "backward_copy_longs") == 0 @@ -93,12 +83,6 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, // When cstack=vm, unwind stub frames one by one pc = link(); } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (entry != NULL && entry[0] == 0xa9bf7bfd) { // The stub begins with @@ -107,23 +91,11 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, if (ip == entry + 1) { sp += 16; pc = ((uintptr_t *)sp)[-1]; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (entry[1] == 0x910003fd && withinCurrentStack(fp)) { sp = fp + 16; fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } } else if (strncmp(name, "indexof_linear_", 15) == 0 && @@ -145,7 +117,6 @@ static inline bool isEntryBarrier(instruction_t *ip) { bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if ((*ip & 0xffe07fff) == 0xa9007bfd) { @@ -154,71 +125,34 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, unsigned int offset = (*ip >> 12) & 0x1f8; sp += offset + 16; pc = link(); - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } } else if (ip > entry && ip[0] == 0x910003fd && ip[-1] == 0xa9bf7bfd) { // stp x29, x30, [sp, #-16]! // mov x29, sp sp += 16; pc = ((uintptr_t *)sp)[-1]; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } } else if (ip > entry + 3 && !nm->isFrameCompleteAt(ip) && (isEntryBarrier(ip) || isEntryBarrier(ip + 1))) { // Frame should be complete at this point sp += nm->frameSize() * sizeof(void *); fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } } else { // Just try pc = link(); } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } bool StackFrame::unwindAtomicStub(const void*& pc) { // VM threads may call generated atomic stubs, which are not normally walkable - const u64 startTime = TSC::ticks(); const void* lr = (const void*)link(); if (VMStructs::libjvm()->contains(lr)) { NMethod* nm = CodeHeap::findNMethod(pc); if (nm != NULL && strncmp(nm->name(), "Stub", 4) == 0) { pc = lr; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_arm.cpp b/ddprof-lib/src/main/cpp/stackFrame_arm.cpp index 755750720..5f72491eb 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_arm.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_arm.cpp @@ -21,9 +21,6 @@ #include #include -#include "counters.h" -#include "tsc.h" - uintptr_t &StackFrame::pc() { return (uintptr_t &)_ucontext->uc_mcontext.arm_pc; } @@ -77,32 +74,18 @@ void StackFrame::ret() { pc() = link(); } bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xe12fff1e || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = link(); - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } - - const u64 endTime = TSC::ticks(); - u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if (ip > entry && ip <= entry + 4 && (*ip & 0xffffff00) == 0xe24dd000) { @@ -112,12 +95,6 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1]; sp += 8; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (*ip == 0xe8bd4800) { // add sp, sp, #offs @@ -125,21 +102,9 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1]; sp += 8; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } pc = link(); - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_i386.cpp b/ddprof-lib/src/main/cpp/stackFrame_i386.cpp index 5279055a9..fdf4159a6 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_i386.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_i386.cpp @@ -21,9 +21,6 @@ #include #include -#include "counters.h" -#include "tsc.h" - uintptr_t &StackFrame::pc() { return (uintptr_t &)_ucontext->uc_mcontext.gregs[REG_EIP]; } @@ -71,19 +68,12 @@ void StackFrame::ret() { bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xc3 || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = *(uintptr_t *)sp; sp += 4; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (entry != NULL && entry[0] == 0x55 && entry[1] == 0x8b && entry[2] == 0xec) { @@ -93,38 +83,19 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, if (ip == entry + 1) { pc = ((uintptr_t *)sp)[1]; sp += 8; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (withinCurrentStack(fp)) { sp = fp + 8; fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if (ip <= entry || *ip == 0xc3 // ret @@ -133,32 +104,14 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, { pc = *(uintptr_t *)sp; sp += 4; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (*ip == 0x5d) { // pop ebp fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1]; sp += 8; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp b/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp index 49b84527b..a06c0c0e1 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_ppc64.cpp @@ -22,9 +22,6 @@ #include #include -#include "counters.h" -#include "tsc.h" - uintptr_t &StackFrame::pc() { return (uintptr_t &)_ucontext->uc_mcontext.regs->nip; } @@ -115,21 +112,12 @@ static inline bool inC2PrologueCrit(uintptr_t pc) { bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); pc = link(); - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); - // On PPC there is a valid back link to the previous frame at all times. The // callee stores the return address in the caller's frame before it constructs // its own frame. After it has destroyed its frame it restores the link @@ -152,12 +140,6 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, pc = link(); } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } diff --git a/ddprof-lib/src/main/cpp/stackFrame_x64.cpp b/ddprof-lib/src/main/cpp/stackFrame_x64.cpp index 049f53449..aa3c99f0b 100644 --- a/ddprof-lib/src/main/cpp/stackFrame_x64.cpp +++ b/ddprof-lib/src/main/cpp/stackFrame_x64.cpp @@ -22,9 +22,6 @@ #include #include -#include "counters.h" -#include "tsc.h" - #ifdef __APPLE__ #define REG(l, m) _ucontext->uc_mcontext->__ss.__##m #else @@ -65,36 +62,18 @@ void StackFrame::ret() { bool StackFrame::unwindStub(instruction_t *entry, const char *name, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; if (ip == entry || *ip == 0xc3 || strncmp(name, "itable", 6) == 0 || strncmp(name, "vtable", 6) == 0 || strcmp(name, "InlineCacheBuffer") == 0) { pc = ((uintptr_t *)sp)[0] - 1; sp += 8; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } if (entry == nullptr) { - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } if (reinterpret_cast(entry) % alignof(unsigned int) != 0) { - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } if (*(unsigned int *)entry == 0xec8b4855) { @@ -104,38 +83,19 @@ bool StackFrame::unwindStub(instruction_t *entry, const char *name, if (ip == entry + 1) { pc = ((uintptr_t *)sp)[1] - 1; sp += 16; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (withinCurrentStack(fp)) { sp = fp + 16; fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1] - 1; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, uintptr_t &fp) { - const u64 startTime = TSC::ticks(); instruction_t *ip = (instruction_t *)pc; instruction_t *entry = (instruction_t *)nm->entry(); if (ip <= entry || *ip == 0xc3 // ret @@ -148,48 +108,23 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, // otherwise it may be attributed to a wrong bytecode pc = ((uintptr_t *)sp)[0] - 1; sp += 8; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) - { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (*ip == 0x5d) { // pop rbp fp = ((uintptr_t *)sp)[0]; pc = ((uintptr_t *)sp)[1] - 1; sp += 16; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (ip <= entry + 15 && ((uintptr_t)ip & 0xfff) && ip[-1] == 0x55) { // push rbp pc = ((uintptr_t *)sp)[1] - 1; sp += 16; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if (ip <= entry + 7 && ip[0] == 0x48 && ip[1] == 0x89 && ip[2] == 0x6c && ip[3] == 0x24) { // mov [rsp + #off], rbp sp += ip[4] + 16; pc = ((uintptr_t *)sp)[-1] - 1; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } else if ((ip[0] == 0x41 && ip[1] == 0x81 && ip[2] == 0x7f && *(u32 *)(ip + 4) == 1) || @@ -200,20 +135,8 @@ bool StackFrame::unwindCompiled(NMethod *nm, uintptr_t &pc, uintptr_t &sp, sp += nm->frameSize() * sizeof(void *); fp = ((uintptr_t *)sp)[-2]; pc = ((uintptr_t *)sp)[-1]; - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return true; } - - const u64 endTime = TSC::ticks(); - const u64 duration = TSC::ticks_to_millis(endTime - startTime); - if (duration > 1) { - Counters::increment(UNWINDING_TIME, duration); - } return false; } diff --git a/ddprof-lib/src/main/cpp/stackWalker.cpp b/ddprof-lib/src/main/cpp/stackWalker.cpp index c39394809..4c668381c 100644 --- a/ddprof-lib/src/main/cpp/stackWalker.cpp +++ b/ddprof-lib/src/main/cpp/stackWalker.cpp @@ -146,7 +146,6 @@ int StackWalker::walkFP(void *ucontext, const void **callchain, int max_depth, sp = fp + (FRAME_PC_SLOT + 1) * sizeof(void *); fp = *(uintptr_t *)fp; } - return depth; }