diff --git a/.github/workflows/test_workflow.yml b/.github/workflows/test_workflow.yml index 8c88a0dc..73d65053 100644 --- a/.github/workflows/test_workflow.yml +++ b/.github/workflows/test_workflow.yml @@ -84,7 +84,7 @@ jobs: export LIBC=glibc export SANITIZER=${{ matrix.config }} - ./gradlew -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs + ./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs EXIT_CODE=$? if [ $EXIT_CODE -ne 0 ]; then @@ -174,7 +174,7 @@ jobs: }') export JAVA_VERSION - ./gradlew -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs + ./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs EXIT_CODE=$? if [ $EXIT_CODE -ne 0 ]; then @@ -274,7 +274,7 @@ jobs: export LIBC=glibc export SANITIZER=${{ matrix.config }} - ./gradlew -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs + ./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs EXIT_CODE=$? if [ $EXIT_CODE -ne 0 ]; then diff --git a/ddprof-lib/gtest/build.gradle b/ddprof-lib/gtest/build.gradle index 3c002fae..dc3e9e7c 100644 --- a/ddprof-lib/gtest/build.gradle +++ b/ddprof-lib/gtest/build.gradle @@ -42,7 +42,7 @@ def buildResourcesTask = tasks.register("buildResources", Exec) { description = "Build the resources for the Google Tests" onlyIf { - hasGtest && !project.hasProperty('skip-native') && os().isLinux() + hasGtest && !project.hasProperty('skip-native') && !project.hasProperty('skip-gtest') && os().isLinux() } def targetDir = project(':ddprof-lib').file('build/test/resources/unresolved-functions') @@ -58,7 +58,7 @@ def buildSmallLibTask = tasks.register("buildSmallLib", Exec) { description = "Build the small-lib shared library for the Google Tests" onlyIf { - hasGtest && !project.hasProperty('skip-native') && os().isLinux() + hasGtest && !project.hasProperty('skip-native') && !project.hasProperty('skip-gtest') && os().isLinux() } def sourceDir = project(':ddprof-lib').file('src/test/resources/small-lib') @@ -77,7 +77,7 @@ def buildSmallLibTask = tasks.register("buildSmallLib", Exec) { def gtestAll = tasks.register("gtest") { onlyIf { - hasGtest && !project.hasProperty('skip-tests') && !project.hasProperty('skip-native') + hasGtest && !project.hasProperty('skip-tests') && !project.hasProperty('skip-native') && !project.hasProperty('skip-gtest') } group = 'verification' description = "Run all Google Tests for all build configurations of the library" @@ -99,6 +99,7 @@ tasks.whenTaskAdded { task -> def gtestCompileTask = tasks.register("compileGtest${config.name.capitalize()}_${testName}", CppCompile) { onlyIf { config.active && hasGtest && !project.hasProperty('skip-tests') && !project.hasProperty('skip-native') + && !project.hasProperty('skip-gtest') } group = 'build' description = "Compile the Google Test ${testName} for the ${config.name} build of the library" @@ -156,6 +157,7 @@ tasks.whenTaskAdded { task -> def gtestLinkTask = tasks.register("linkGtest${config.name.capitalize()}_${testName}", LinkExecutable) { onlyIf { config.active && hasGtest && !project.hasProperty('skip-tests') && !project.hasProperty('skip-native') + && !project.hasProperty('skip-gtest') } group = 'build' description = "Link the Google Test for the ${config.name} build of the library" @@ -180,6 +182,7 @@ tasks.whenTaskAdded { task -> def gtestExecuteTask = tasks.register("gtest${config.name.capitalize()}_${testName}", Exec) { onlyIf { config.active && hasGtest && !project.hasProperty('skip-tests') && !project.hasProperty('skip-native') + && !project.hasProperty('skip-gtest') } group = 'verification' description = "Run the Google Test ${testName} for the ${config.name} build of the library" diff --git a/ddprof-lib/src/main/cpp/arguments.cpp b/ddprof-lib/src/main/cpp/arguments.cpp index 588e6ec2..051755af 100644 --- a/ddprof-lib/src/main/cpp/arguments.cpp +++ b/ddprof-lib/src/main/cpp/arguments.cpp @@ -277,21 +277,18 @@ Error Arguments::parse(const char *args) { CASE("cstack") if (value != NULL) { - switch (value[0]) { - case 'n': - _cstack = CSTACK_NO; - break; - case 'd': + if (strcmp(value, "fp") == 0) { + _cstack = CSTACK_FP; + } else if (strcmp(value, "dwarf") == 0) { _cstack = CSTACK_DWARF; - break; - case 'l': + } else if (strcmp(value, "lbr") == 0) { _cstack = CSTACK_LBR; - break; - case 'v': + } else if (strcmp(value, "vm") == 0) { _cstack = CSTACK_VM; - break; - default: - _cstack = CSTACK_FP; + } else if (strcmp(value, "vmx") == 0) { + _cstack = CSTACK_VMX; + } else { + _cstack = CSTACK_NO; } } diff --git a/ddprof-lib/src/main/cpp/arguments.h b/ddprof-lib/src/main/cpp/arguments.h index f693ae7a..3ef8a5b8 100644 --- a/ddprof-lib/src/main/cpp/arguments.h +++ b/ddprof-lib/src/main/cpp/arguments.h @@ -61,12 +61,13 @@ enum Style { }; enum CStack { - CSTACK_DEFAULT, - CSTACK_NO, - CSTACK_FP, - CSTACK_DWARF, - CSTACK_LBR, - CSTACK_VM + CSTACK_DEFAULT, // use perf_event_open stack if available or Frame Pointer links otherwise + CSTACK_NO, // do not collect native frames + CSTACK_FP, // walk stack using Frame Pointer links + CSTACK_DWARF, // use DWARF unwinding info from .eh_frame section + CSTACK_LBR, // Last Branch Record hardware capability + CSTACK_VM, // unwind using HotSpot VMStructs + CSTACK_VMX // same as CSTACK_VM but with intermediate native frames }; enum Output { OUTPUT_NONE, OUTPUT_COLLAPSED, OUTPUT_JFR }; diff --git a/ddprof-lib/src/main/cpp/dwarf.h b/ddprof-lib/src/main/cpp/dwarf.h index 91e1746b..70d73ebd 100644 --- a/ddprof-lib/src/main/cpp/dwarf.h +++ b/ddprof-lib/src/main/cpp/dwarf.h @@ -55,7 +55,13 @@ const int DW_REG_FP = 29; const int DW_REG_SP = 31; const int DW_REG_PC = 30; const int EMPTY_FRAME_SIZE = 0; -const int LINKED_FRAME_SIZE = 0; + +// aarch64 function prologue looks like this (if frame pointer is used): +// stp x29, x30, [sp, -16]! // Save FP (x29) and LR (x30) +// mov x29, sp // Set FP to SP +// --- +// LINKED_FRAME_SIZE should be 16 +const int LINKED_FRAME_SIZE = 2 * DW_STACK_SLOT; #else diff --git a/ddprof-lib/src/main/cpp/flightRecorder.cpp b/ddprof-lib/src/main/cpp/flightRecorder.cpp index 08ae4b70..2e0bef3e 100644 --- a/ddprof-lib/src/main/cpp/flightRecorder.cpp +++ b/ddprof-lib/src/main/cpp/flightRecorder.cpp @@ -751,13 +751,15 @@ void Recording::writeSettings(Buffer *buf, Arguments &args) { writeBoolSetting(buf, T_HEAP_LIVE_OBJECT, "enabled", args._record_liveness); writeBoolSetting(buf, T_ACTIVE_RECORDING, "debugSymbols", - VMStructs::hasDebugSymbols()); + VMStructs::libjvm()->hasDebugSymbols()); writeBoolSetting(buf, T_ACTIVE_RECORDING, "kernelSymbols", Symbols::haveKernelSymbols()); writeStringSetting(buf, T_ACTIVE_RECORDING, "cpuEngine", Profiler::instance()->cpuEngine()->name()); writeStringSetting(buf, T_ACTIVE_RECORDING, "wallEngine", Profiler::instance()->wallEngine()->name()); + writeStringSetting(buf, T_ACTIVE_RECORDING, "cstack", + Profiler::instance()->cstack()); flushIfNeeded(buf); } diff --git a/ddprof-lib/src/main/cpp/profiler.cpp b/ddprof-lib/src/main/cpp/profiler.cpp index 52f9370f..8adb74fb 100644 --- a/ddprof-lib/src/main/cpp/profiler.cpp +++ b/ddprof-lib/src/main/cpp/profiler.cpp @@ -17,7 +17,6 @@ #include "profiler.h" #include "asyncSampleMutex.h" -#include "common.h" #include "context.h" #include "counters.h" #include "ctimer.h" @@ -289,7 +288,7 @@ int Profiler::getNativeTrace(void *ucontext, ASGCT_CallFrame *frames, PerfEvents::walkKernel(tid, callchain + native_frames, MAX_NATIVE_FRAMES - native_frames, java_ctx); } - if (_cstack == CSTACK_VM) { + if (_cstack >= CSTACK_VM) { return 0; } else if (_cstack == CSTACK_DWARF) { native_frames += StackWalker::walkDwarf(ucontext, callchain + native_frames, @@ -406,7 +405,7 @@ int Profiler::getJavaTraceAsync(void *ucontext, ASGCT_CallFrame *frames, if (in_java && java_ctx->sp != 0) { // skip ahead to the Java frames before calling AGCT frame.restore((uintptr_t)java_ctx->pc, java_ctx->sp, java_ctx->fp); - } else if (state != 0 && vm_thread->lastJavaSP() == 0) { + } else if (state != 0 && (vm_thread->anchor() == nullptr || vm_thread->anchor()->lastJavaSP() == 0)) { // we haven't found the top Java frame ourselves, and the lastJavaSP wasn't // recorded either when not in the Java state, lastJava ucontext will be // used by AGCT @@ -485,14 +484,16 @@ int Profiler::getJavaTraceAsync(void *ucontext, ASGCT_CallFrame *frames, } } else if (trace.num_frames == ticks_unknown_not_Java && !(_safe_mode & LAST_JAVA_PC)) { - uintptr_t &sp = vm_thread->lastJavaSP(); - uintptr_t &pc = vm_thread->lastJavaPC(); - if (sp != 0 && pc == 0) { + JavaFrameAnchor* anchor = vm_thread->anchor(); + uintptr_t sp = anchor->lastJavaSP(); + const void* pc = anchor->lastJavaPC(); + if (sp != 0 && pc == NULL) { // We have the last Java frame anchor, but it is not marked as walkable. // Make it walkable here - pc = ((uintptr_t *)sp)[-1]; + pc = ((const void**)sp)[-1]; + anchor->setLastJavaPC(pc); - NMethod *m = CodeHeap::findNMethod((const void *)pc); + NMethod *m = CodeHeap::findNMethod(pc); if (m != NULL) { // AGCT fails if the last Java frame is a Runtime Stub with an invalid // _frame_complete_offset. In this case we patch _frame_complete_offset @@ -502,20 +503,21 @@ int Profiler::getJavaTraceAsync(void *ucontext, ASGCT_CallFrame *frames, m->setFrameCompleteOffset(0); } VM::_asyncGetCallTrace(&trace, max_depth, ucontext); - } else if (_libs->findLibraryByAddress((const void *)pc) != NULL) { + } else if (_libs->findLibraryByAddress(pc) != NULL) { VM::_asyncGetCallTrace(&trace, max_depth, ucontext); } - pc = 0; + anchor->setLastJavaPC(nullptr); } } else if (trace.num_frames == ticks_not_walkable_not_Java && !(_safe_mode & LAST_JAVA_PC)) { - uintptr_t &sp = vm_thread->lastJavaSP(); - uintptr_t &pc = vm_thread->lastJavaPC(); - if (sp != 0 && pc != 0) { + JavaFrameAnchor* anchor = vm_thread->anchor(); + uintptr_t sp = anchor->lastJavaSP(); + const void* pc = anchor->lastJavaPC(); + if (sp != 0 && pc != NULL) { // Similar to the above: last Java frame is set, // but points to a Runtime Stub with an invalid _frame_complete_offset - NMethod *m = CodeHeap::findNMethod((const void *)pc); + NMethod *m = CodeHeap::findNMethod(pc); if (m != NULL && !m->isNMethod() && m->frameSize() > 0 && m->frameCompleteOffset() == -1) { m->setFrameCompleteOffset(0); @@ -523,7 +525,7 @@ int Profiler::getJavaTraceAsync(void *ucontext, ASGCT_CallFrame *frames, } } } else if (trace.num_frames == ticks_GC_active && !(_safe_mode & GC_TRACES)) { - if (vm_thread->lastJavaSP() == 0) { + if (vm_thread->anchor()->lastJavaSP() == 0) { // Do not add 'GC_active' for threads with no Java frames, e.g. Compiler // threads frame.restore(saved_pc, saved_sp, saved_fp); @@ -682,28 +684,32 @@ void Profiler::recordSample(void *ucontext, u64 counter, int tid, ASGCT_CallFrame *native_stop = frames + num_frames; num_frames += getNativeTrace(ucontext, native_stop, event_type, tid, &java_ctx, &truncated); - if (_cstack == CSTACK_VM) { - num_frames += - StackWalker::walkVM(ucontext, frames + num_frames, _max_stack_depth, - _call_stub_begin, _call_stub_end); + if (_cstack == CSTACK_VMX) { + num_frames += StackWalker::walkVM(ucontext, frames + num_frames, _max_stack_depth, VM_EXPERT, &truncated); } else if (event_type == BCI_CPU || event_type == BCI_WALL) { - int java_frames = 0; - { + if (_cstack == CSTACK_VM) { + num_frames += StackWalker::walkVM(ucontext, frames + num_frames, _max_stack_depth, VM_NORMAL, &truncated); + } else { // Async events AsyncSampleMutex mutex(ProfiledThread::current()); + int java_frames = 0; if (mutex.acquired()) { - java_frames = - getJavaTraceAsync(ucontext, frames + num_frames, _max_stack_depth, - &java_ctx, &truncated); + java_frames = getJavaTraceAsync(ucontext, frames + num_frames, _max_stack_depth, &java_ctx, &truncated); + if (java_frames > 0 && java_ctx.pc != NULL && VMStructs::hasMethodStructs()) { + NMethod* nmethod = CodeHeap::findNMethod(java_ctx.pc); + if (nmethod != NULL) { + fillFrameTypes(frames + num_frames, java_frames, nmethod); + } + } } - } - if (java_frames > 0 && java_ctx.pc != NULL) { - NMethod *nmethod = CodeHeap::findNMethod(java_ctx.pc); - if (nmethod != NULL) { - fillFrameTypes(frames + num_frames, java_frames, nmethod); + if (java_frames > 0 && java_ctx.pc != NULL) { + NMethod *nmethod = CodeHeap::findNMethod(java_ctx.pc); + if (nmethod != NULL) { + fillFrameTypes(frames + num_frames, java_frames, nmethod); + } } + num_frames += java_frames; } - num_frames += java_frames; } if (num_frames == 0) { @@ -1069,7 +1075,7 @@ Error Profiler::checkJvmCapabilities() { } } - if (!VMStructs::hasDebugSymbols() && !VM::isOpenJ9()) { + if (!VMStructs::libjvm()->hasDebugSymbols() && !VM::isOpenJ9()) { Log::warn("Install JVM debug symbols to improve profile accuracy"); } @@ -1162,7 +1168,6 @@ Error Profiler::start(Arguments &args, bool reset) { return Error( "VMStructs stack walking is not supported on this JVM/platform"); } - Log::info("cstack=vm is an experimental option, use with care"); } // Kernel symbols are useful only for perf_events without --all-user @@ -1292,7 +1297,7 @@ Error Profiler::check(Arguments &args) { return Error("DWARF unwinding is not supported on this platform"); } else if (args._cstack == CSTACK_LBR && _cpu_engine != &perf_events) { return Error("Branch stack is supported only with PMU events"); - } else if (args._cstack == CSTACK_VM && !VMStructs::hasStackStructs()) { + } else if (_cstack >= CSTACK_VM && !(VMStructs::hasStackStructs() && OS::isLinux())) { return Error( "VMStructs stack walking is not supported on this JVM/platform"); } diff --git a/ddprof-lib/src/main/cpp/profiler.h b/ddprof-lib/src/main/cpp/profiler.h index eeaf2ad9..7e90918e 100644 --- a/ddprof-lib/src/main/cpp/profiler.h +++ b/ddprof-lib/src/main/cpp/profiler.h @@ -1,17 +1,6 @@ /* - * Copyright 2016 Andrei Pangin - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. + * Copyright The async-profiler authors + * SPDX-License-Identifier: Apache-2.0 */ #ifndef _PROFILER_H @@ -180,6 +169,19 @@ class Profiler { return _instance; } + const char* cstack() { + switch (_cstack) { + case CSTACK_DEFAULT: return "default"; + case CSTACK_NO: return "no"; + case CSTACK_FP: return "fp"; + case CSTACK_DWARF: return "dwarf"; + case CSTACK_LBR: return "lbr"; + case CSTACK_VM: return "vm"; + case CSTACK_VMX: return "vmx"; + default: return "default"; + } + } + u64 total_samples() { return _total_samples; } int max_stack_depth() { return _max_stack_depth; } time_t uptime() { return time(NULL) - _start_time; } @@ -213,7 +215,8 @@ class Profiler { Error stop(); Error flushJfr(); Error dump(const char *path, const int length); - void switchThreadEvents(jvmtiEventMode mode); + void logStats(); + void switchThreadEvents(jvmtiEventMode mode); int convertNativeTrace(int native_frames, const void **callchain, ASGCT_CallFrame *frames); void recordSample(void *ucontext, u64 weight, int tid, jint event_type, diff --git a/ddprof-lib/src/main/cpp/stackWalker.cpp b/ddprof-lib/src/main/cpp/stackWalker.cpp index 7e19ed69..eb795f21 100644 --- a/ddprof-lib/src/main/cpp/stackWalker.cpp +++ b/ddprof-lib/src/main/cpp/stackWalker.cpp @@ -158,8 +158,7 @@ int StackWalker::walkDwarf(void *ucontext, const void **callchain, } if (CodeHeap::contains(pc) && !(depth == 0 && frame.unwindAtomicStub(pc))) { const void* page_start = (const void*)((uintptr_t)pc & ~0xfffUL); - // Don't dereference pc as it may point to unreadable memory - // frame.adjustSP(page_start, pc, sp); + frame.adjustSP(page_start, pc, sp); java_ctx->set(pc, sp, fp); break; } @@ -218,39 +217,19 @@ int StackWalker::walkDwarf(void *ucontext, const void **callchain, break; } } - - if (inDeadZone(pc)) { - *truncated = pc != NULL; - break; - } } - return depth; } -#ifdef __aarch64__ -// we are seeing false alarms on aarch64 GHA runners due to 'heap-use-after-free' -__attribute__((no_sanitize("address"))) -#endif -int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, - const void *_termination_frame_begin, - const void *_termination_frame_end) { - const void *pc; - uintptr_t fp; - uintptr_t sp; - uintptr_t bottom = (uintptr_t)&sp + MAX_WALK_SIZE; - +int StackWalker::walkVM(void* ucontext, ASGCT_CallFrame* frames, int max_depth, + StackDetail detail, const void* pc, uintptr_t sp, uintptr_t fp, bool *truncated) { StackFrame frame(ucontext); - if (ucontext == NULL) { - pc = __builtin_return_address(0); - fp = (uintptr_t)__builtin_frame_address(1); - sp = (uintptr_t)__builtin_frame_address(0); - } else { - pc = (const void *)frame.pc(); - fp = frame.fp(); - sp = frame.sp(); - } + uintptr_t bottom = (uintptr_t)&frame + MAX_WALK_SIZE; + if (inDeadZone(pc)) { + *truncated = pc != NULL; + return 0; + } Profiler *profiler = Profiler::instance(); Libraries *libraries = Libraries::instance(); @@ -277,9 +256,6 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, // Walk until the bottom of the stack or until the first Java frame while (depth < max_depth) { - if (pc >= _termination_frame_begin && pc < _termination_frame_end) { - break; - } if (CodeHeap::contains(pc)) { // constant time NMethod *nm = CodeHeap::findNMethod(pc); @@ -287,7 +263,7 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, fillFrame(frames[depth++], BCI_ERROR, "unknown_nmethod"); } else if (nm->isNMethod()) { int level = nm->level(); - FrameTypeId type = + FrameTypeId type = detail != VM_BASIC && level >= 1 && level <= 3 ? FRAME_C1_COMPILED : FRAME_JIT_COMPILED; fillFrame(frames[depth++], type, 0, nm->method()->id()); @@ -302,9 +278,10 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, fillFrame(frames[depth++], BCI_ERROR, "unknown_scope"); break; } - type = scope_offset > 0 ? FRAME_INLINED - : level >= 1 && level <= 3 ? FRAME_C1_COMPILED - : FRAME_JIT_COMPILED; + if (detail != VM_BASIC) { + type = scope_offset > 0 ? FRAME_INLINED : + level >= 1 && level <= 3 ? FRAME_C1_COMPILED : FRAME_JIT_COMPILED; + } fillFrame(frames[depth++], type, scope.bci(), scope.method()->id()); } while (scope_offset > 0 && depth < max_depth); @@ -374,12 +351,34 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, fillFrame(frames[depth++], BCI_ERROR, "break_interpreted"); break; + } else if (detail < VM_EXPERT && nm->isEntryFrame(pc)) { + JavaFrameAnchor* anchor = JavaFrameAnchor::fromEntryFrame(fp); + if (anchor == NULL) { + fillFrame(frames[depth++], BCI_ERROR, "break_entry_frame"); + break; + } + uintptr_t prev_sp = sp; + sp = anchor->lastJavaSP(); + fp = anchor->lastJavaFP(); + pc = anchor->lastJavaPC(); + if (sp == 0 || pc == NULL) { + // End of Java stack + break; + } + if (sp < prev_sp || sp >= bottom || !aligned(sp)) { + fillFrame(frames[depth++], BCI_ERROR, "break_entry_frame"); + break; + } + continue; } else { // linear time in number of runtime stubs CodeBlob *stub = profiler->findRuntimeStub(pc); const void *start = stub != NULL ? stub->_start : nm->code(); const char *name = stub != NULL ? stub->_name : nm->name(); - fillFrame(frames[depth++], BCI_NATIVE_FRAME, name); + + if (detail != VM_BASIC) { + fillFrame(frames[depth++], BCI_NATIVE_FRAME, name); + } if (frame.unwindStub((instruction_t *)start, name, (uintptr_t &)pc, sp, fp)) { @@ -398,7 +397,10 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, cc = libraries->findLibraryByAddress(pc); } const char *name = cc == NULL ? NULL : cc->binarySearch(pc); - fillFrame(frames[depth++], BCI_NATIVE_FRAME, name); + + if (detail != VM_BASIC) { + fillFrame(frames[depth++], BCI_NATIVE_FRAME, name); + } } uintptr_t prev_sp = sp; @@ -413,7 +415,7 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, cc != NULL ? cc->findFrameDesc(pc) : &FrameDesc::default_frame; u8 cfa_reg = (u8)f->cfa; - int cfa_off = f->cfa >> 8; + int cfa_off = f->cfa >> 16; if (cfa_reg == DW_REG_SP) { sp = sp + cfa_off; } else if (cfa_reg == DW_REG_FP) { @@ -467,6 +469,43 @@ int StackWalker::walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, return depth; } +int StackWalker::walkVM(void* ucontext, ASGCT_CallFrame* frames, int max_depth, JavaFrameAnchor* anchor, bool *truncated) { + uintptr_t sp = anchor->lastJavaSP(); + if (sp == 0) { + *truncated = true; + return 0; + } + + uintptr_t fp = anchor->lastJavaFP(); + if (fp == 0) { + fp = sp; + } + + const void* pc = anchor->lastJavaPC(); + if (pc == NULL) { + pc = ((const void**)sp)[-1]; + } + + return walkVM(ucontext, frames, max_depth, VM_BASIC, pc, sp, fp, truncated); +} + + +#ifdef __aarch64__ +// we are seeing false alarms on aarch64 GHA runners due to 'heap-use-after-free' +__attribute__((no_sanitize("address"))) +#endif +int StackWalker::walkVM(void* ucontext, ASGCT_CallFrame* frames, int max_depth, StackDetail detail, bool *truncated) { + if (ucontext == NULL) { + const void* pc = __builtin_return_address(0); + uintptr_t sp = (uintptr_t)__builtin_frame_address(0) + LINKED_FRAME_SIZE; + uintptr_t fp = (uintptr_t)__builtin_frame_address(1); + return walkVM(ucontext, frames, max_depth, detail, pc, sp, fp, truncated); + } else { + StackFrame frame(ucontext); + return walkVM(ucontext, frames, max_depth, detail, (const void*)frame.pc(), frame.sp(), frame.fp(), truncated); + } +} + void StackWalker::checkFault(ProfiledThread* thrd) { VMThread *vm_thread = VMThread::current(); if (vm_thread != NULL && sameStack(vm_thread->exception(), &vm_thread)) { diff --git a/ddprof-lib/src/main/cpp/stackWalker.h b/ddprof-lib/src/main/cpp/stackWalker.h index 7c47b9d4..3412ea2e 100644 --- a/ddprof-lib/src/main/cpp/stackWalker.h +++ b/ddprof-lib/src/main/cpp/stackWalker.h @@ -22,6 +22,8 @@ #include #include +class JavaFrameAnchor; + struct StackContext { const void *pc; uintptr_t sp; @@ -34,15 +36,25 @@ struct StackContext { } }; +// Detail level of VMStructs stack walking +enum StackDetail { + VM_BASIC, // only basic Java frames similar to what AsyncGetCallTrace provides + VM_NORMAL, // include frame types and runtime stubs + VM_EXPERT // all features: frame types, runtime stubs, and intermediate native frames +}; + class StackWalker { +private: + static int walkVM(void* ucontext, ASGCT_CallFrame* frames, int max_depth, + StackDetail detail, const void* pc, uintptr_t sp, uintptr_t fp, bool *truncated); + public: static int walkFP(void *ucontext, const void **callchain, int max_depth, StackContext *java_ctx, bool *truncated); static int walkDwarf(void *ucontext, const void **callchain, int max_depth, StackContext *java_ctx, bool *truncated); - static int walkVM(void *ucontext, ASGCT_CallFrame *frames, int max_depth, - const void *_termination_frame_begin, - const void *_termination_frame_end); + static int walkVM(void* ucontext, ASGCT_CallFrame* frames, int max_depth, StackDetail detail, bool *truncated); + static int walkVM(void* ucontext, ASGCT_CallFrame* frames, int max_depth, JavaFrameAnchor* anchor, bool *truncated); static void checkFault(ProfiledThread* thrd); }; diff --git a/ddprof-lib/src/main/cpp/vmStructs.cpp b/ddprof-lib/src/main/cpp/vmStructs.cpp index 3b10c14d..1a882b79 100644 --- a/ddprof-lib/src/main/cpp/vmStructs.cpp +++ b/ddprof-lib/src/main/cpp/vmStructs.cpp @@ -49,10 +49,11 @@ int VMStructs::_thread_anchor_offset = -1; int VMStructs::_thread_state_offset = -1; int VMStructs::_thread_vframe_offset = -1; int VMStructs::_thread_exception_offset = -1; +int VMStructs::_osthread_id_offset = -1; +int VMStructs::_call_wrapper_anchor_offset = -1; int VMStructs::_comp_env_offset = -1; int VMStructs::_comp_task_offset = -1; int VMStructs::_comp_method_offset = -1; -int VMStructs::_osthread_id_offset = -1; int VMStructs::_osthread_state_offset = -1; int VMStructs::_anchor_sp_offset = -1; int VMStructs::_anchor_pc_offset = -1; @@ -98,6 +99,7 @@ char **VMStructs::_code_heap_addr = NULL; const void **VMStructs::_code_heap_low_addr = NULL; const void **VMStructs::_code_heap_high_addr = NULL; int *VMStructs::_klass_offset_addr = NULL; +int VMStructs::_entry_frame_call_wrapper_offset = -1; int VMStructs::_interpreter_frame_bcp_offset = 0; unsigned char VMStructs::_unsigned5_base = 0; const void **VMStructs::_call_stub_return_addr = NULL; @@ -109,9 +111,7 @@ jfieldID VMStructs::_eetop; jfieldID VMStructs::_tid; jfieldID VMStructs::_klass = NULL; int VMStructs::_tls_index = -1; -intptr_t VMStructs::_env_offset; -VMStructs::GetStackTraceFunc VMStructs::_get_stack_trace = NULL; VMStructs::LockFunc VMStructs::_lock_func; VMStructs::LockFunc VMStructs::_unlock_func; @@ -260,6 +260,10 @@ void VMStructs::initOffsets() { } else if (strcmp(field, "_state") == 0) { _osthread_state_offset = *(int *)(entry + offset_offset); } + } else if (strcmp(type, "JavaCallWrapper") == 0) { + if (strcmp(field, "_anchor") == 0) { + _call_wrapper_anchor_offset = *(int*)(entry + offset_offset); + } } else if (strcmp(type, "JavaFrameAnchor") == 0) { if (strcmp(field, "_last_Java_sp") == 0) { _anchor_sp_offset = *(int *)(entry + offset_offset); @@ -367,6 +371,25 @@ void VMStructs::initOffsets() { _constmethod_size = *(int *)(entry + size_offset); } } + + entry = readSymbol("gHotSpotVMIntConstants"); + stride = readSymbol("gHotSpotVMIntConstantEntryArrayStride"); + uintptr_t name_offset = readSymbol("gHotSpotVMIntConstantEntryNameOffset"); + uintptr_t value_offset = readSymbol("gHotSpotVMIntConstantEntryValueOffset"); + + if (entry != 0 && stride != 0) { + for (;; entry += stride) { + const char* name = *(const char**)(entry + name_offset); + if (name == NULL) { + break; + } + + if (strcmp(name, "frame::entry_frame_call_wrapper_offset") == 0) { + _entry_frame_call_wrapper_offset = *(int*)(entry + value_offset) * sizeof(uintptr_t); + break; // remove it for reading more constants + } + } + } } void VMStructs::resolveOffsets() { @@ -400,6 +423,8 @@ void VMStructs::resolveOffsets() { _interpreter_frame_bcp_offset = VM::hotspot_version() >= 11 ? -9 : VM::hotspot_version() == 8 ? -7 : 0; + // The constant is missing on ARM, but fortunately, it has been stable for years across all JDK versions + _entry_frame_call_wrapper_offset = -64; #endif // JDK-8292758 has slightly changed ScopeDesc encoding @@ -416,14 +441,18 @@ void VMStructs::resolveOffsets() { _data_offset = 0; } - _has_stack_structs = - _has_method_structs && _interpreter_frame_bcp_offset != 0 && - _code_offset != -1 && _scopes_data_offset != -1 && - _data_offset >= 0 && - _scopes_pcs_offset >= 0 && - _nmethod_immutable_offset < 0 // TODO: not yet supported - && _nmethod_metadata_offset >= 0 && _thread_vframe_offset >= 0 && - _thread_exception_offset >= 0 && _constmethod_size >= 0; + _has_stack_structs = _has_method_structs + && _call_wrapper_anchor_offset >= 0 + && _entry_frame_call_wrapper_offset != -1 + && _interpreter_frame_bcp_offset != 0 + && _code_offset != -1 + && _data_offset >= 0 + && _scopes_data_offset != -1 + && _scopes_pcs_offset >= 0 + && _nmethod_metadata_offset >= 0 + && _thread_vframe_offset >= 0 + && _thread_exception_offset >= 0 + && _constmethod_size >= 0; if (_code_heap_addr != NULL && _code_heap_low_addr != NULL && _code_heap_high_addr != NULL) { @@ -513,9 +542,6 @@ const void *VMStructs::findHeapUsageFunc() { } void VMStructs::initJvmFunctions() { - _get_stack_trace = (GetStackTraceFunc)_libjvm->findSymbolByPrefix( - "_ZN8JvmtiEnv13GetStackTraceEP10JavaThreadiiP"); - if (VM::hotspot_version() == 8) { _lock_func = (LockFunc)_libjvm->findSymbol( "_ZN7Monitor28lock_without_safepoint_checkEv"); @@ -593,7 +619,6 @@ void VMStructs::initThreadBridge(JNIEnv *env) { // HotSpot VMThread *vm_thread = VMThread::fromJavaThread(env, thread); if (vm_thread != NULL) { - _env_offset = (intptr_t)env - (intptr_t)vm_thread; _has_native_thread_id = _thread_osthread_offset >= 0 && _osthread_id_offset >= 0; initTLS(vm_thread); diff --git a/ddprof-lib/src/main/cpp/vmStructs.h b/ddprof-lib/src/main/cpp/vmStructs.h index f6ede92f..b57afa39 100644 --- a/ddprof-lib/src/main/cpp/vmStructs.h +++ b/ddprof-lib/src/main/cpp/vmStructs.h @@ -60,6 +60,7 @@ class VMStructs { static int _thread_exception_offset; static int _osthread_id_offset; static int _osthread_state_offset; + static int _call_wrapper_anchor_offset; static int _comp_env_offset; static int _comp_task_offset; static int _comp_method_offset; @@ -118,6 +119,7 @@ class VMStructs { static int _region_size_offset; static int _markword_klass_shift; static int _markword_monitor_value; + static int _entry_frame_call_wrapper_offset; static int _interpreter_frame_bcp_offset; static unsigned char _unsigned5_base; static const void **_call_stub_return_addr; @@ -129,7 +131,6 @@ class VMStructs { static jfieldID _tid; static jfieldID _klass; static int _tls_index; - static intptr_t _env_offset; typedef void (*LockFunc)(void *); static LockFunc _lock_func; @@ -161,6 +162,10 @@ class VMStructs { static void initUnsafeFunctions(); static void initMemoryUsage(JNIEnv *env); + static bool goodPtr(const void* ptr) { + return (uintptr_t)ptr >= 0x1000 && ((uintptr_t)ptr & (sizeof(uintptr_t) - 1)) == 0; + } + const char *at(int offset) { return (const char *)this + offset; } static bool aligned(const void *ptr) { @@ -201,15 +206,6 @@ class VMStructs { pc < _interpreted_frame_valid_end; } - typedef jvmtiError (*GetStackTraceFunc)(void *self, void *thread, - jint start_depth, - jint max_frame_count, - jvmtiFrameInfo *frame_buffer, - jint *count_ptr); - static GetStackTraceFunc _get_stack_trace; - - static bool hasDebugSymbols() { return _get_stack_trace != NULL; } - static bool isSafeToWalk(uintptr_t pc); static void JNICALL NativeMethodBind(jvmtiEnv *jvmti, JNIEnv *jni, @@ -427,6 +423,36 @@ enum JVMJavaThreadState { _thread_max_state = 12 // maximum thread state+1 - used for statistics allocation }; +class JavaFrameAnchor : VMStructs { + private: + enum { MAX_CALL_WRAPPER_DISTANCE = 512 }; + + public: + static JavaFrameAnchor* fromEntryFrame(uintptr_t fp) { + const char* call_wrapper = *(const char**)(fp + _entry_frame_call_wrapper_offset); + if (!goodPtr(call_wrapper) || (uintptr_t)call_wrapper - fp > MAX_CALL_WRAPPER_DISTANCE) { + return NULL; + } + return (JavaFrameAnchor*)(call_wrapper + _call_wrapper_anchor_offset); + } + + uintptr_t lastJavaSP() { + return *(uintptr_t*) at(_anchor_sp_offset); + } + + uintptr_t lastJavaFP() { + return *(uintptr_t*) at(_anchor_fp_offset); + } + + const void* lastJavaPC() { + return *(const void**) at(_anchor_pc_offset); + } + + void setLastJavaPC(const void* pc) { + *(const void**) at(_anchor_pc_offset) = pc; + } +}; + class VMThread : VMStructs { public: static VMThread *current(); @@ -439,10 +465,6 @@ class VMThread : VMStructs { : NULL; } - static VMThread *fromEnv(JNIEnv *env) { - return (VMThread *)((intptr_t)env - _env_offset); - } - static jlong javaThreadId(JNIEnv *env, jthread thread) { return env->GetLongField(thread, _tid); } @@ -475,16 +497,8 @@ class VMThread : VMStructs { return ThreadState::UNKNOWN; } - uintptr_t &lastJavaSP() { - return *(uintptr_t *)(at(_thread_anchor_offset) + _anchor_sp_offset); - } - - uintptr_t &lastJavaPC() { - return *(uintptr_t *)(at(_thread_anchor_offset) + _anchor_pc_offset); - } - - uintptr_t &lastJavaFP() { - return *(uintptr_t *)(at(_thread_anchor_offset) + _anchor_fp_offset); + JavaFrameAnchor* anchor() { + return (JavaFrameAnchor*) at(_thread_anchor_offset); } VMMethod *compiledMethod() { diff --git a/ddprof-lib/src/main/java/com/datadoghq/profiler/Platform.java b/ddprof-lib/src/main/java/com/datadoghq/profiler/Platform.java index 6bc7d06e..51c72132 100644 --- a/ddprof-lib/src/main/java/com/datadoghq/profiler/Platform.java +++ b/ddprof-lib/src/main/java/com/datadoghq/profiler/Platform.java @@ -1,5 +1,6 @@ package com.datadoghq.profiler; +import java.io.IOException; import java.lang.management.GarbageCollectorMXBean; import java.lang.management.ManagementFactory; @@ -327,4 +328,13 @@ public static String getRuntimePatches() { public static boolean isAarch64() { return System.getProperty("os.arch").toLowerCase().contains("aarch64"); } + + public static boolean isMusl() { + try { + OperatingSystem current = OperatingSystem.current(); + return current == OperatingSystem.linux && current.isMusl(); + } catch (IOException e) { + throw new RuntimeException(e); + } + } } diff --git a/ddprof-test/build.gradle b/ddprof-test/build.gradle index 48dcce0d..c2f88149 100644 --- a/ddprof-test/build.gradle +++ b/ddprof-test/build.gradle @@ -81,7 +81,7 @@ tasks.withType(Test).configureEach { def keepRecordings = project.hasProperty("keepJFRs") || Boolean.parseBoolean(System.getenv("KEEP_JFRS")) jvmArgs "-Dddprof_test.keep_jfrs=${keepRecordings}", '-Djdk.attach.allowAttachSelf', '-Djol.tryWithSudo=true', - "-Dddprof_test.config=${config}", '-XX:ErrorFile=build/hs_err_pid%p.log', '-XX:+ResizeTLAB', + "-Dddprof_test.config=${config}", "-Dddprof_test.ci=${project.hasProperty('CI')}", '-XX:ErrorFile=build/hs_err_pid%p.log', '-XX:+ResizeTLAB', '-Xmx512m' def javaHome = System.getenv("JAVA_TEST_HOME") diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/AbstractProfilerTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/AbstractProfilerTest.java index 1ffa9c94..b37ba6e3 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/AbstractProfilerTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/AbstractProfilerTest.java @@ -1,14 +1,15 @@ package com.datadoghq.profiler; -import java.lang.reflect.Method; import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.Paths; import java.time.Duration; import java.util.Arrays; +import java.util.Collections; +import java.util.HashMap; import java.util.HashSet; +import java.util.Map; import java.util.Set; -import java.util.UUID; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.Assertions; @@ -38,7 +39,6 @@ import org.openjdk.jmc.flightrecorder.jdk.JdkAttributes; public abstract class AbstractProfilerTest { - private static final boolean ALLOW_NATIVE_CSTACKS = true; private boolean stopped = true; @@ -97,6 +97,24 @@ public IMemberAccessor customAccessor(IType type) { private Duration cpuInterval; private Duration wallInterval; + private Map testParams; + + protected static Map mapOf(Object ... vals) { + Map map = new HashMap<>(); + for (int i = 0; i < vals.length; i += 2) { + map.put(vals[i].toString(), vals[i + 1]); + } + return map; + } + + protected AbstractProfilerTest(Map testParams) { + this.testParams = testParams != null ? new HashMap<>(testParams) : Collections.emptyMap(); + } + + protected AbstractProfilerTest() { + this(null); + } + private static Duration parseInterval(String command, String part) { String prefix = part + "="; int start = command.indexOf(prefix); @@ -156,7 +174,14 @@ public void setupProfiler(TestInfo testInfo) throws Exception { Path rootDir = Paths.get("/tmp/recordings"); Files.createDirectories(rootDir); - jfrDump = Files.createTempFile(rootDir, testConfig.replace('/', '_') + "-" + testInfo.getTestMethod().map(m -> m.getDeclaringClass().getSimpleName() + "_" + m.getName()).orElse("unknown"), ".jfr"); + String cstack = (String)testParams.get("cstack"); + + if (cstack != null) { + rootDir = rootDir.resolve(cstack); + Files.createDirectories(rootDir); + } + + jfrDump = Files.createTempFile(rootDir, (testConfig.isEmpty() ? "" : testConfig.replace('/', '_') + "-") + testInfo.getTestMethod().map(m -> m.getDeclaringClass().getSimpleName() + "_" + m.getName()).orElse("unknown"), ".jfr"); profiler = JavaProfiler.getInstance(); String command = "start," + getAmendedProfilerCommand() + ",jfr,file=" + jfrDump.toAbsolutePath(); cpuInterval = command.contains("cpu") ? parseInterval(command, "cpu") : (command.contains("interval") ? parseInterval(command, "interval") : Duration.ZERO); @@ -183,6 +208,10 @@ protected void before() throws Exception { protected void after() throws Exception { } + protected final boolean isInCI() { + return Boolean.getBoolean("ddprof_test.ci"); + } + private void checkConfig() { try { IItemCollection profilerConfig = verifyEvents("datadog.DatadogProfilerConfig"); @@ -228,7 +257,7 @@ protected void runTests(Runnable... runnables) throws InterruptedException { } - protected void stopProfiler() { + public final void stopProfiler() { if (!stopped) { profiler.stop(); stopped = true; @@ -242,18 +271,22 @@ protected void dump(Path recording) { } } - protected void registerCurrentThreadForWallClockProfiling() { + public final void registerCurrentThreadForWallClockProfiling() { profiler.addThread(); } private String getAmendedProfilerCommand() { String profilerCommand = getProfilerCommand(); - return (ALLOW_NATIVE_CSTACKS || profilerCommand.contains("cstack=") - ? profilerCommand - : profilerCommand + ",cstack=fp") - // FIXME - test framework doesn't seem to be forking each test, so need to sync - // these across test cases for now - + ",attributes=tag1;tag2;tag3"; + String testCstack = (String)testParams.get("cstack"); + if (testCstack != null) { + profilerCommand += ",cstack=" + testCstack; + } else if(!(ALLOW_NATIVE_CSTACKS || profilerCommand.contains("cstack="))) { + profilerCommand += ",cstack=fp"; + } + // FIXME - test framework doesn't seem to be forking each test, so need to sync + // these across test cases for now + profilerCommand += ",attributes=tag1;tag2;tag3"; + return profilerCommand; } protected abstract String getProfilerCommand(); @@ -263,7 +296,7 @@ protected void verifyEventsPresent(String... expectedEventTypes) { verifyEventsPresent(jfrDump, expectedEventTypes); } - protected void verifyEventsPresent(Path recording, String... expectedEventTypes) { + protected void verifyEventsPresent(Path recording, String... expectedEventTypes) { try { IItemCollection events = JfrLoaderToolkit.loadEvents(Files.newInputStream(recording)); assertTrue(events.hasItems()); @@ -278,7 +311,7 @@ protected void verifyEventsPresent(Path recording, String... expectedEventTypes) } } - protected IItemCollection verifyEvents(String eventType) { + public final IItemCollection verifyEvents(String eventType) { return verifyEvents(eventType, true); } @@ -303,6 +336,25 @@ protected IItemCollection verifyEvents(Path recording, String eventType, boolean } } + protected final void verifyCStackSettings() { + String cstack = (String)testParams.get("cstack"); + if (cstack == null) { + // not a forced cstack mode + return; + } + IItemCollection settings = verifyEvents("jdk.ActiveSetting"); + for (IItemIterable settingEvents : settings) { + IMemberAccessor nameAccessor = JdkAttributes.REC_SETTING_NAME.getAccessor(settingEvents.getType()); + IMemberAccessor valueAccessor = JdkAttributes.REC_SETTING_VALUE.getAccessor(settingEvents.getType()); + for (IItem item : settingEvents) { + String name = nameAccessor.getMember(item); + if (name.equals("cstack")) { + assertEquals(cstack, valueAccessor.getMember(item)); + } + } + } + } + protected void verifyStackTraces(String eventType, String... patterns) { verifyStackTraces(jfrDump, eventType, patterns); } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/CStackAwareAbstractProfilerTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/CStackAwareAbstractProfilerTest.java new file mode 100644 index 00000000..3cf797ab --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/CStackAwareAbstractProfilerTest.java @@ -0,0 +1,13 @@ +package com.datadoghq.profiler; + + +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.CStackInjector; +import org.junit.jupiter.api.extension.ExtendWith; + +@ExtendWith(CStackInjector.class) +public abstract class CStackAwareAbstractProfilerTest extends AbstractProfilerTest { + public CStackAwareAbstractProfilerTest(@CStack String cstack) { + super(mapOf("cstack", cstack)); + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/CTimerSamplerTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/CTimerSamplerTest.java index 2482f85e..aa276a4b 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/CTimerSamplerTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/CTimerSamplerTest.java @@ -1,9 +1,15 @@ package com.datadoghq.profiler.cpu; import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.CStackAwareAbstractProfilerTest; import com.datadoghq.profiler.Platform; +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.CStackInjector; +import com.datadoghq.profiler.junit.RetryTest; import org.junit.jupiter.api.Assumptions; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.TestTemplate; +import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.ValueSource; import org.junitpioneer.jupiter.RetryingTest; @@ -22,23 +28,32 @@ import static org.junit.jupiter.api.Assumptions.assumeFalse; import static org.junit.jupiter.api.Assumptions.assumeTrue; -public class CTimerSamplerTest extends AbstractProfilerTest { +public class CTimerSamplerTest extends CStackAwareAbstractProfilerTest { private ProfiledCode profiledCode; + public CTimerSamplerTest(@CStack String cstack) { + super(cstack); + } + @Override protected void before() { profiledCode = new ProfiledCode(profiler); } - @RetryingTest(10) - public void test() throws ExecutionException, InterruptedException { + @RetryTest(10) + @TestTemplate + @ValueSource(strings = {"fp", "dwarf", "vm", "vmx"}) + public void test(@CStack String cstack) throws ExecutionException, InterruptedException { // timer_create is available on Linux only assumeTrue(Platform.isLinux()); for (int i = 0, id = 1; i < 100; i++, id += 3) { profiledCode.method1(id); } stopProfiler(); + + verifyCStackSettings(); + IItemCollection events = verifyEvents("datadog.ExecutionSample"); for (IItemIterable cpuSamples : events) { diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/ContextCpuTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/ContextCpuTest.java index 65cc2d18..a195e4d7 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/ContextCpuTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/ContextCpuTest.java @@ -7,8 +7,15 @@ import static org.junit.jupiter.api.Assertions.assertDoesNotThrow; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertTrue; + +import com.datadoghq.profiler.CStackAwareAbstractProfilerTest; +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.CStackInjector; +import com.datadoghq.profiler.junit.RetryTest; import org.junit.jupiter.api.Assumptions; -import org.junitpioneer.jupiter.RetryingTest; +import org.junit.jupiter.api.TestTemplate; +import org.junit.jupiter.api.extension.ExtendWith; +import org.junit.jupiter.params.provider.ValueSource; import org.openjdk.jmc.common.item.IItem; import org.openjdk.jmc.common.item.IItemCollection; import org.openjdk.jmc.common.item.IItemIterable; @@ -20,22 +27,31 @@ import static com.datadoghq.profiler.MoreAssertions.assertInRange; import com.datadoghq.profiler.Platform; -public class ContextCpuTest extends AbstractProfilerTest { +public class ContextCpuTest extends CStackAwareAbstractProfilerTest { private ProfiledCode profiledCode; + public ContextCpuTest(@CStack String cstack) { + super(cstack); + } + @Override protected void before() { profiledCode = new ProfiledCode(profiler); } - @RetryingTest(10) - public void test() throws ExecutionException, InterruptedException { + @RetryTest(10) + @TestTemplate + @ValueSource(strings = {"fp", "dwarf", "vm", "vmx"}) + public void test(@CStack String cstack) throws ExecutionException, InterruptedException { Assumptions.assumeTrue(!Platform.isJ9()); for (int i = 0, id = 1; i < 100; i++, id += 3) { profiledCode.method1(id); } stopProfiler(); + + verifyCStackSettings(); + Set method1SpanIds = profiledCode.spanIdsForMethod("method1Impl"); Set method2SpanIds = profiledCode.spanIdsForMethod("method2Impl"); Set method3SpanIds = profiledCode.spanIdsForMethod("method3Impl"); diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/SmokeCpuTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/SmokeCpuTest.java index 7fd46586..01787d24 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/SmokeCpuTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/SmokeCpuTest.java @@ -1,6 +1,11 @@ package com.datadoghq.profiler.cpu; import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.CStackAwareAbstractProfilerTest; +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.RetryTest; +import org.junit.jupiter.api.TestTemplate; +import org.junit.jupiter.params.provider.ValueSource; import org.junitpioneer.jupiter.RetryingTest; import org.openjdk.jmc.common.item.IItem; import org.openjdk.jmc.common.item.IItemCollection; @@ -11,31 +16,47 @@ import java.util.concurrent.ExecutionException; import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + import com.datadoghq.profiler.Platform; -public class SmokeCpuTest extends AbstractProfilerTest { +public class SmokeCpuTest extends CStackAwareAbstractProfilerTest { private ProfiledCode profiledCode; + public SmokeCpuTest(@CStack String cstack) { + super(cstack); + } + @Override protected void before() { profiledCode = new ProfiledCode(profiler); } - @RetryingTest(10) - public void test() throws ExecutionException, InterruptedException { + @RetryTest(10) + @TestTemplate + @ValueSource(strings = {"fp", "dwarf", "vm", "vmx"}) + public void test(@CStack String cstack) throws ExecutionException, InterruptedException { for (int i = 0, id = 1; i < 100; i++, id += 3) { profiledCode.method1(id); } stopProfiler(); + + verifyCStackSettings(); + IItemCollection events = verifyEvents("datadog.ExecutionSample"); // on mac the usage of itimer to drive the sampling provides very unreliable outputs - if (!Platform.isMac()) { - for (IItemIterable cpuSamples : events) { - IMemberAccessor frameAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(cpuSamples.getType()); - for (IItem sample : cpuSamples) { - String stackTrace = frameAccessor.getMember(sample); - assertFalse(stackTrace.contains("jvmtiError")); + for (IItemIterable cpuSamples : events) { + IMemberAccessor frameAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(cpuSamples.getType()); + for (IItem sample : cpuSamples) { + String stackTrace = frameAccessor.getMember(sample); + assertFalse(stackTrace.contains("jvmtiError")); + if ("vmx".equals(stackTrace)) { + // extra checks to make sure we see the mixed stacktraces + assertTrue(stackTrace.contains("JavaCalls::call_virtual()"), + "JavaCalls::call_virtual() (above call_stub) found in stack trace"); + assertTrue(stackTrace.contains("call_stub()"), + "call_stub() (sentinel value used to halt unwinding) found in stack trace"); } } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/VMStructsBasedCpuTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/VMStructsBasedCpuTest.java deleted file mode 100644 index 991e4ae7..00000000 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/cpu/VMStructsBasedCpuTest.java +++ /dev/null @@ -1,62 +0,0 @@ -package com.datadoghq.profiler.cpu; - -import com.datadoghq.profiler.AbstractProfilerTest; -import com.datadoghq.profiler.Platform; -import org.junit.jupiter.api.Assumptions; -import org.junit.jupiter.api.Test; -import org.openjdk.jmc.common.item.IItem; -import org.openjdk.jmc.common.item.IItemCollection; -import org.openjdk.jmc.common.item.IItemIterable; -import org.openjdk.jmc.common.item.IMemberAccessor; -import org.openjdk.jmc.flightrecorder.jdk.JdkAttributes; - -import java.util.concurrent.ExecutionException; - -import static org.junit.jupiter.api.Assertions.assertFalse; - - -public class VMStructsBasedCpuTest extends AbstractProfilerTest { - - private ProfiledCode profiledCode; - - @Override - protected void withTestAssumptions() { - // vmstructs based stackwalking will throw ISE on Java 23 - Assumptions.assumeFalse(Platform.isJavaVersionAtLeast(23)); - } - - @Override - protected void before() { - // vmstructs based stackwalking will throw ISE on Java 23 - Assumptions.assumeFalse(Platform.isJavaVersionAtLeast(23)); - profiledCode = new ProfiledCode(profiler); - } - - @Test - public void test() throws ExecutionException, InterruptedException { - for (int i = 0, id = 1; i < 100; i++, id += 3) { - profiledCode.method1(id); - } - stopProfiler(); - IItemCollection events = verifyEvents("datadog.ExecutionSample"); - for (IItemIterable it : events) { - IMemberAccessor stackTraceAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(it.getType()); - for (IItem item : it) { - String stacktrace = stackTraceAccessor.getMember(item); - assertFalse(stacktrace.contains("JavaCalls::call_virtual()"), - "JavaCalls::call_virtual() (above call_stub) found in stack trace"); - assertFalse(stacktrace.contains("call_stub()"), - "call_stub() (sentinel value used to halt unwinding) found in stack trace"); - } - } - } - - @Override - protected String getProfilerCommand() { - return "cpu=10ms" + (vmstructsUnwinderSupported() ? ",cstack=vm" : ""); - } - - private boolean vmstructsUnwinderSupported() { - return !Platform.isJ9() && !Platform.isZing(); - } -} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/junit/CStack.java b/ddprof-test/src/test/java/com/datadoghq/profiler/junit/CStack.java new file mode 100644 index 00000000..de1cf009 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/junit/CStack.java @@ -0,0 +1,11 @@ +package com.datadoghq.profiler.junit; + +import java.lang.annotation.ElementType; +import java.lang.annotation.Retention; +import java.lang.annotation.RetentionPolicy; +import java.lang.annotation.Target; + +@Target(ElementType.PARAMETER) +@Retention(RetentionPolicy.RUNTIME) +public @interface CStack { +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/junit/CStackInjector.java b/ddprof-test/src/test/java/com/datadoghq/profiler/junit/CStackInjector.java new file mode 100644 index 00000000..5aba5f56 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/junit/CStackInjector.java @@ -0,0 +1,176 @@ +package com.datadoghq.profiler.junit; + +import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.Platform; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.TestInfo; +import org.junit.jupiter.api.extension.Extension; +import org.junit.jupiter.api.extension.ExtensionContext; +import org.junit.jupiter.api.extension.InvocationInterceptor; +import org.junit.jupiter.api.extension.ParameterContext; +import org.junit.jupiter.api.extension.ParameterResolutionException; +import org.junit.jupiter.api.extension.ParameterResolver; +import org.junit.jupiter.api.extension.TestExecutionExceptionHandler; +import org.junit.jupiter.api.extension.TestTemplateInvocationContext; +import org.junit.jupiter.api.extension.TestTemplateInvocationContextProvider; +import org.junit.jupiter.params.provider.ValueSource; +import org.opentest4j.TestAbortedException; + +import java.lang.reflect.InvocationTargetException; +import java.lang.reflect.Method; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.Collections; +import java.util.List; +import java.util.Optional; +import java.util.Set; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.stream.Collectors; +import java.util.stream.Stream; + +public class CStackInjector implements TestTemplateInvocationContextProvider { + + @Override + public boolean supportsTestTemplate(ExtensionContext context) { + return context.getTestMethod().isPresent() && + context.getTestMethod().get().isAnnotationPresent(ValueSource.class); + } + + @Override + public Stream provideTestTemplateInvocationContexts(ExtensionContext context) { + ValueSource valueSource = context.getTestMethod().get().getAnnotation(ValueSource.class); + // Get retry count from @RetryTest (default = 0) + int retryCount = context.getTestMethod() + .flatMap(method -> Optional.ofNullable(method.getAnnotation(RetryTest.class))) + .map(RetryTest::value) + .orElse(0); + if (Platform.isZing()) { + // zing is a bit iffy when using anything but 'no' for cstack + return Stream.of(new ParameterizedTestContext("no", retryCount)); + } else { + return Stream.of(valueSource.strings()). + filter(param -> (!Platform.isJ9() || !param.startsWith("vm"))). + map(param -> new ParameterizedTestContext(param, retryCount)); + } + } + + public static class TestInfoAdapter implements TestInfo { + private final String displayName; + private final Set tags; + private final Class testClass; + private final Method testMethod; + + public TestInfoAdapter(String displayName, Set tags, Class testClass, Method testMethod) { + this.displayName = displayName; + this.tags = tags; + this.testClass = testClass; + this.testMethod = testMethod; + } + + @Override + public String getDisplayName() { + return displayName; + } + + @Override + public Set getTags() { + return tags; + } + + @Override + public Optional> getTestClass() { + return Optional.ofNullable(testClass); + } + + @Override + public Optional getTestMethod() { + return Optional.ofNullable(testMethod); + } + } + + private static class ParameterizedTestContext implements TestTemplateInvocationContext { + private final String parameter; + private final int retryCount; + + ParameterizedTestContext(String parameter, int retryCount) { + this.parameter = parameter; + this.retryCount = retryCount; + } + + @Override + public String getDisplayName(int invocationIndex) { + return "cstack=" + parameter; + } + + @Override + public List getAdditionalExtensions() { + List extensions = new ArrayList<>(TestTemplateInvocationContext.super.getAdditionalExtensions()); + extensions.add( + new ParameterResolver() { + @Override + public boolean supportsParameter(ParameterContext parameterContext, ExtensionContext extensionContext) + throws ParameterResolutionException { + return parameterContext.getParameter().getType() == String.class && parameterContext.getParameter().isAnnotationPresent(CStack.class); + } + + @Override + public Object resolveParameter(ParameterContext parameterContext, ExtensionContext extensionContext) + throws ParameterResolutionException { + return parameter; + } + } + ); + extensions.add( + (TestExecutionExceptionHandler) (extensionContext, throwable) -> { + int attempt = 0; + while (++attempt < retryCount) { + System.out.println("[Retrying] Attempt " + attempt + "/" + retryCount + " due to failure: " + throwable.getMessage()); + // Manually reinvoke the test method + Method testMethod = extensionContext.getRequiredTestMethod(); + Object testInstance = extensionContext.getRequiredTestInstance(); + Class testClass = extensionContext.getRequiredTestClass(); + String displayName = extensionContext.getDisplayName(); + TestInfoAdapter testInfo = new TestInfoAdapter(displayName, Collections.emptySet(), testClass, testMethod); + + List afterEachMethods = Arrays.stream(testInstance.getClass().getMethods()) + .filter(method -> method.isAnnotationPresent(AfterEach.class)) + .collect(Collectors.toList()); + List beforeEachMethods = Arrays.stream(testInstance.getClass().getMethods()) + .filter(method -> method.isAnnotationPresent(BeforeEach.class)) + .collect(Collectors.toList()); + // Retry the test method + try { + for (Method method : afterEachMethods) { + if (method.getParameterTypes().length == 1 && method.getParameterTypes()[0].isAssignableFrom(TestInfo.class)) { + method.invoke(testInstance, testInfo); + } else { + method.invoke(testInstance); + } + } + for (Method method : beforeEachMethods) { + if (method.getParameterTypes().length == 1 && method.getParameterTypes()[0].isAssignableFrom(TestInfo.class)) { + method.invoke(testInstance, testInfo); + } else { + method.invoke(testInstance); + } + } + testMethod.invoke(testInstance, parameter); + return; // If the test passes, stop retrying + } catch (InvocationTargetException e) { + throwable = e.getTargetException(); + } catch (Throwable t) { + throwable = t; + } + } + + System.out.println("[Failure] Test failed after " + retryCount + " attempts."); + throw throwable; + } + ); + return extensions; + } + + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/junit/RetryTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/junit/RetryTest.java new file mode 100644 index 00000000..28675251 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/junit/RetryTest.java @@ -0,0 +1,12 @@ +package com.datadoghq.profiler.junit; + +import java.lang.annotation.ElementType; +import java.lang.annotation.Retention; +import java.lang.annotation.RetentionPolicy; +import java.lang.annotation.Target; + +@Target(ElementType.METHOD) +@Retention(RetentionPolicy.RUNTIME) +public @interface RetryTest { + int value() default 5; +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/BaseContextWallClockTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/BaseContextWallClockTest.java new file mode 100644 index 00000000..2c3b3392 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/BaseContextWallClockTest.java @@ -0,0 +1,222 @@ +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.JavaProfiler; +import com.datadoghq.profiler.Platform; +import com.datadoghq.profiler.context.ContextExecutor; +import com.datadoghq.profiler.context.Tracing; +import org.junit.jupiter.api.Assumptions; +import org.openjdk.jmc.common.item.IItem; +import org.openjdk.jmc.common.item.IItemCollection; +import org.openjdk.jmc.common.item.IItemIterable; +import org.openjdk.jmc.common.item.IMemberAccessor; +import org.openjdk.jmc.common.unit.IQuantity; +import org.openjdk.jmc.flightrecorder.jdk.JdkAttributes; + +import java.util.HashSet; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.CopyOnWriteArrayList; +import java.util.concurrent.ExecutionException; +import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; +import java.util.function.Supplier; + +import static com.datadoghq.profiler.AbstractProfilerTest.*; +import static com.datadoghq.profiler.MoreAssertions.assertInRange; +import static org.junit.jupiter.api.Assertions.*; + +final class BaseContextWallClockTest { + private final Supplier profilerRef; + private volatile JavaProfiler profiler; + + private ContextExecutor executor; + + private Map> methodsToSpanIds; + + BaseContextWallClockTest(Supplier profilerRef) { + this.profilerRef = profilerRef; + } + + void before() { + profiler = profilerRef.get(); + executor = new ContextExecutor(1, profiler); + methodsToSpanIds = new ConcurrentHashMap<>(); + } + + void after() throws InterruptedException { + executor.shutdownNow(); + executor.awaitTermination(30, TimeUnit.SECONDS); + profiler = null; + } + + void test(AbstractProfilerTest test) throws ExecutionException, InterruptedException { + Assumptions.assumeTrue(!Platform.isJ9() && !Platform.isZing()); + + test.registerCurrentThreadForWallClockProfiling(); + for (int i = 0, id = 1; i < 100; i++, id += 3) { + method1(id); + } + test.stopProfiler(); + Set method1SpanIds = new HashSet<>(methodsToSpanIds.get("method1Impl")); + Set method2SpanIds = new HashSet<>(methodsToSpanIds.get("method2Impl")); + Set method3SpanIds = new HashSet<>(methodsToSpanIds.get("method3Impl")); + IItemCollection events = test.verifyEvents("datadog.MethodSample"); + Set states = new HashSet<>(); + Set modes = new HashSet<>(); + // we have 100 method1, method2, and method3 calls, but can't guarantee we sampled them all + long method1Weight = 0; + long method2Weight = 0; + long method3Weight = 0; + long unattributedWeight = 0; + for (IItemIterable wallclockSamples : events) { + IMemberAccessor frameAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(wallclockSamples.getType()); + IMemberAccessor spanIdAccessor = SPAN_ID.getAccessor(wallclockSamples.getType()); + IMemberAccessor rootSpanIdAccessor = LOCAL_ROOT_SPAN_ID.getAccessor(wallclockSamples.getType()); + IMemberAccessor weightAccessor = WEIGHT.getAccessor(wallclockSamples.getType()); + IMemberAccessor stateAccessor = THREAD_STATE.getAccessor(wallclockSamples.getType()); + IMemberAccessor modeAccessor = THREAD_EXECUTION_MODE.getAccessor(wallclockSamples.getType()); + for (IItem sample : wallclockSamples) { + String stackTrace = frameAccessor.getMember(sample); + long spanId = spanIdAccessor.getMember(sample).longValue(); + long rootSpanId = rootSpanIdAccessor.getMember(sample).longValue(); + long weight = weightAccessor.getMember(sample).longValue(); + modes.add(modeAccessor.getMember(sample)); + String state = stateAccessor.getMember(sample); + assertNotNull(state); + states.add(state); + // a lot fo care needs to be taken here with samples that fall between a context activation and + // a method call. E.g. not finding method2Impl in the stack trace doesn't mean the sample wasn't + // taken in the part of method2 between activation and invoking method2Impl, which complicates + // assertions when we only find method1Impl + if (stackTrace.contains("method3Impl")) { + // method3 is scheduled after method2, and method1 blocks on it, so spanId == rootSpanId + 2 + assertEquals(rootSpanId + 2, spanId, stackTrace); + assertTrue(spanId == 0 || method3SpanIds.contains(spanId), stackTrace); + method3Weight += weight; + } else if (stackTrace.contains("method2Impl")) { + // method2 is called next, so spanId == rootSpanId + 1 + assertEquals(rootSpanId + 1, spanId, stackTrace); + assertTrue(spanId == 0 || method2SpanIds.contains(spanId), stackTrace); + method2Weight += weight; + } else if (stackTrace.contains("method1Impl") + && !stackTrace.contains("method2") && !stackTrace.contains("method3")) { + // need to check this after method2 because method1 calls method2 + // it's the root so spanId == rootSpanId + assertEquals(rootSpanId, spanId, stackTrace); + assertTrue(spanId == 0 || method1SpanIds.contains(spanId), stackTrace); + method1Weight += weight; + } + assertTrue(weight <= 10 && weight > 0); + if (spanId == 0) { + unattributedWeight += weight; + } + } + } + if (!Platform.isJ9() && Platform.isJavaVersionAtLeast(11)) { + assertTrue(states.contains("WAITING"), "no WAITING samples"); + assertTrue(states.contains("PARKED"), "no PARKED samples"); + assertTrue(states.contains("CONTENDED"), "no CONTENDED samples"); + } else { + assertTrue(states.contains("SYSCALL"), "no SYSCALL samples"); + } + + if (!Platform.isZing() && !Platform.isJ9()) { + assertTrue(modes.contains("JAVA") || modes.contains("JVM"), "no JAVA|JVM samples"); + assertFalse(modes.contains("UNKNOWN"), "UNKNOWN wallclock samples on HotSpot"); + } else { + assertTrue(modes.contains("UNKNOWN"), "no UNKNOWN samples"); + } + + // TODO: vmstructs unwinding on Liberica and aarch64 creates a higher number of broken frames + // it is under investigation but until it gets resolved we will just relax the error margin + double allowedError = Platform.isAarch64() && "BellSoft".equals(System.getProperty("java.vendor")) ? 0.4d : 0.2d; + + // context filtering should prevent these + assertFalse(states.contains("NEW")); + assertFalse(states.contains("TERMINATED")); + double totalWeight = method1Weight + method2Weight + method3Weight + unattributedWeight; + // method1 has ~50% self time, 50% calling method2 + assertWeight("method1Impl", totalWeight, method1Weight, 0.33, allowedError); + // method2 has as much self time as method1 + assertWeight("method2Impl", totalWeight, method2Weight, 0.33, allowedError); + // method3 has as much self time as method1, and should account for half the executor's thread's time + assertWeight("method3Impl", totalWeight, method3Weight, 0.33, allowedError); + Map debugCounters = profiler.getDebugCounters(); + // these are here to verify these counters produce reasonable values so they can be used for memory leak detection + assertInRange(debugCounters.get("calltrace_storage_traces"), 1, 100); + assertInRange(debugCounters.get("calltrace_storage_bytes"), 1024, 8 * 1024 * 1024); + // this allocator is only used for calltrace storage and eagerly allocates chunks of 8MiB + assertEquals(0, debugCounters.get("linear_allocator_bytes")); + assertEquals(0, debugCounters.get("linear_allocator_chunks")); + assertInRange(debugCounters.get("thread_ids_count"), 1, 100); + assertInRange(debugCounters.get("thread_names_count"), 1, 100); + } + + private void assertWeight(String name, double total, long weight, double expected, double allowedError) { + assertTrue(Math.abs(weight / total - expected) < allowedError, String.format("expect %f weight for %s but have %f", expected, name, weight / total)); + } + + public void method1(int id) throws ExecutionException, InterruptedException { + try (Tracing.Context context = Tracing.newContext(() -> id, profiler)) { + method1Impl(id, context); + } + } + + public void method1Impl(int id, Tracing.Context context) throws ExecutionException, InterruptedException { + sleep(10); + Object monitor = new Object(); + Future wait = executor.submit(() -> method3(id, monitor)); + method2(id, monitor); + synchronized (monitor) { + monitor.wait(10); + } + wait.get(); + record("method1Impl", context); + } + + public void method2(long id, Object monitor) { + synchronized (monitor) { + try (Tracing.Context context = Tracing.newContext(() -> id + 1, profiler)) { + method2Impl(context); + monitor.notify(); + } + } + } + + public void method2Impl(Tracing.Context context) { + sleep(10); + record("method2Impl", context); + } + + public void method3(long id, Object monitor) { + synchronized (monitor) { + try (Tracing.Context context = Tracing.newContext(() -> id + 2, profiler)) { + method3Impl(context); + monitor.notify(); + } + } + } + + public void method3Impl(Tracing.Context context) { + sleep(10); + record("method3Impl", context); + } + + + private void record(String methodName, Tracing.Context context) { + methodsToSpanIds.computeIfAbsent(methodName, k -> new CopyOnWriteArrayList<>()) + .add(context.getSpanId()); + } + + + private void sleep(long millis) { + try { + Thread.sleep(millis); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + } + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContendedWallclockSamplesTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContendedWallclockSamplesTest.java index 35bc9d81..17d7dbbb 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContendedWallclockSamplesTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContendedWallclockSamplesTest.java @@ -1,10 +1,13 @@ package com.datadoghq.profiler.wallclock; -import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.CStackAwareAbstractProfilerTest; import com.datadoghq.profiler.Platform; import com.datadoghq.profiler.context.ContextExecutor; +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.RetryTest; import org.junit.jupiter.api.Assumptions; -import org.junitpioneer.jupiter.RetryingTest; +import org.junit.jupiter.api.TestTemplate; +import org.junit.jupiter.params.provider.ValueSource; import org.openjdk.jmc.common.item.IItem; import org.openjdk.jmc.common.item.IItemIterable; import org.openjdk.jmc.common.item.IMemberAccessor; @@ -18,9 +21,15 @@ import java.util.concurrent.atomic.AtomicLong; import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.junit.jupiter.api.Assumptions.assumeFalse; +import static org.junit.jupiter.api.Assumptions.assumeTrue; -public class ContendedWallclockSamplesTest extends AbstractProfilerTest { +public class ContendedWallclockSamplesTest extends CStackAwareAbstractProfilerTest { + public ContendedWallclockSamplesTest(@CStack String cstack) { + super(cstack); + } + @Override protected String getProfilerCommand() { return "wall=1ms"; @@ -38,15 +47,27 @@ public void after() { executor.shutdownNow(); } - @RetryingTest(5) - public void test() { - Assumptions.assumeFalse(Platform.isZing() || Platform.isJ9()); + @RetryTest(10) + @TestTemplate + @ValueSource(strings = {"fp", "dwarf", "vm", "vmx"}) + public void test(@CStack String cstack) { + assumeFalse(Platform.isZing() || Platform.isJ9()); + // on aarch64 and JDK 8 the vmstructs unwinding for wallclock is extremely unreliable + // ; perhaps due to something missing in the unwinder but until we figure it out we will just not run the tests in CI + assumeTrue(!isInCI() || !Platform.isAarch64() || !cstack.startsWith("vm") || Platform.isJavaVersionAtLeast(11)); + // TODO: investigate why this test fails on musl + // on musl the missing fp unwinding makes the wallclock tests unreliable + assumeTrue(!Platform.isMusl() || !cstack.startsWith("vm")); + long result = 0; for (int i = 0; i < 10; i++) { result += pingPong(); } assertTrue(result != 0); stopProfiler(); + + verifyCStackSettings(); + String lambdaName = getClass().getName() + LAMBDA_QUALIFIER; String lambdaStateName = getClass().getName() + ".lambda$pingPong$"; for (IItemIterable wallclockSamples : verifyEvents("datadog.MethodSample")) { diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContextWallClockTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContextWallClockTest.java index 843f7ae7..62bca3de 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContextWallClockTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ContextWallClockTest.java @@ -1,216 +1,45 @@ package com.datadoghq.profiler.wallclock; -import java.util.HashSet; -import java.util.List; -import java.util.Map; -import java.util.Set; -import java.util.concurrent.ConcurrentHashMap; -import java.util.concurrent.CopyOnWriteArrayList; import java.util.concurrent.ExecutionException; -import java.util.concurrent.Future; -import java.util.concurrent.TimeUnit; -import static org.junit.jupiter.api.Assertions.assertEquals; -import static org.junit.jupiter.api.Assertions.assertFalse; -import static org.junit.jupiter.api.Assertions.assertNotNull; -import static org.junit.jupiter.api.Assertions.assertTrue; -import org.junit.jupiter.api.Assumptions; -import org.junitpioneer.jupiter.RetryingTest; -import org.openjdk.jmc.common.item.IItem; -import org.openjdk.jmc.common.item.IItemCollection; -import org.openjdk.jmc.common.item.IItemIterable; -import org.openjdk.jmc.common.item.IMemberAccessor; -import org.openjdk.jmc.common.unit.IQuantity; -import org.openjdk.jmc.flightrecorder.jdk.JdkAttributes; - -import com.datadoghq.profiler.AbstractProfilerTest; -import static com.datadoghq.profiler.MoreAssertions.assertInRange; +import com.datadoghq.profiler.CStackAwareAbstractProfilerTest; import com.datadoghq.profiler.Platform; -import com.datadoghq.profiler.context.ContextExecutor; -import com.datadoghq.profiler.context.Tracing; +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.RetryTest; +import org.junit.jupiter.api.Assumptions; +import org.junit.jupiter.api.TestTemplate; +import org.junit.jupiter.params.provider.ValueSource; -public class ContextWallClockTest extends AbstractProfilerTest { +import static org.junit.jupiter.api.Assumptions.assumeTrue; - private ContextExecutor executor; +public class ContextWallClockTest extends CStackAwareAbstractProfilerTest { + private final BaseContextWallClockTest base = new BaseContextWallClockTest(() -> profiler); - private Map> methodsToSpanIds; + public ContextWallClockTest(@CStack String cstack) { + super(cstack); + } @Override protected void before() { - executor = new ContextExecutor(1, profiler); - methodsToSpanIds = new ConcurrentHashMap<>(); - } - - @RetryingTest(5) - public void test() throws ExecutionException, InterruptedException { - Assumptions.assumeTrue(!Platform.isJ9() && !Platform.isZing()); - - registerCurrentThreadForWallClockProfiling(); - for (int i = 0, id = 1; i < 100; i++, id += 3) { - method1(id); - } - stopProfiler(); - Set method1SpanIds = new HashSet<>(methodsToSpanIds.get("method1Impl")); - Set method2SpanIds = new HashSet<>(methodsToSpanIds.get("method2Impl")); - Set method3SpanIds = new HashSet<>(methodsToSpanIds.get("method3Impl")); - IItemCollection events = verifyEvents("datadog.MethodSample"); - Set states = new HashSet<>(); - Set modes = new HashSet<>(); - // we have 100 method1, method2, and method3 calls, but can't guarantee we sampled them all - long method1Weight = 0; - long method2Weight = 0; - long method3Weight = 0; - long unattributedWeight = 0; - for (IItemIterable wallclockSamples : events) { - IMemberAccessor frameAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(wallclockSamples.getType()); - IMemberAccessor spanIdAccessor = SPAN_ID.getAccessor(wallclockSamples.getType()); - IMemberAccessor rootSpanIdAccessor = LOCAL_ROOT_SPAN_ID.getAccessor(wallclockSamples.getType()); - IMemberAccessor weightAccessor = WEIGHT.getAccessor(wallclockSamples.getType()); - IMemberAccessor stateAccessor = THREAD_STATE.getAccessor(wallclockSamples.getType()); - IMemberAccessor modeAccessor = THREAD_EXECUTION_MODE.getAccessor(wallclockSamples.getType()); - for (IItem sample : wallclockSamples) { - String stackTrace = frameAccessor.getMember(sample); - long spanId = spanIdAccessor.getMember(sample).longValue(); - long rootSpanId = rootSpanIdAccessor.getMember(sample).longValue(); - long weight = weightAccessor.getMember(sample).longValue(); - modes.add(modeAccessor.getMember(sample)); - String state = stateAccessor.getMember(sample); - assertNotNull(state); - states.add(state); - // a lot fo care needs to be taken here with samples that fall between a context activation and - // a method call. E.g. not finding method2Impl in the stack trace doesn't mean the sample wasn't - // taken in the part of method2 between activation and invoking method2Impl, which complicates - // assertions when we only find method1Impl - if (stackTrace.contains("method3Impl")) { - // method3 is scheduled after method2, and method1 blocks on it, so spanId == rootSpanId + 2 - assertEquals(rootSpanId + 2, spanId, stackTrace); - assertTrue(spanId == 0 || method3SpanIds.contains(spanId), stackTrace); - method3Weight += weight; - } else if (stackTrace.contains("method2Impl")) { - // method2 is called next, so spanId == rootSpanId + 1 - assertEquals(rootSpanId + 1, spanId, stackTrace); - assertTrue(spanId == 0 || method2SpanIds.contains(spanId), stackTrace); - method2Weight += weight; - } else if (stackTrace.contains("method1Impl") - && !stackTrace.contains("method2") && !stackTrace.contains("method3")) { - // need to check this after method2 because method1 calls method2 - // it's the root so spanId == rootSpanId - assertEquals(rootSpanId, spanId, stackTrace); - assertTrue(spanId == 0 || method1SpanIds.contains(spanId), stackTrace); - method1Weight += weight; - } - assertTrue(weight <= 10 && weight > 0); - if (spanId == 0) { - unattributedWeight += weight; - } - } - } - if (!Platform.isJ9() && Platform.isJavaVersionAtLeast(11)) { - assertTrue(states.contains("WAITING"), "no WAITING samples"); - assertTrue(states.contains("PARKED"), "no PARKED samples"); - assertTrue(states.contains("CONTENDED"), "no CONTENDED samples"); - } else { - assertTrue(states.contains("SYSCALL"), "no SYSCALL samples"); - } - - if (!Platform.isZing() && !Platform.isJ9()) { - assertTrue(modes.contains("JAVA") || modes.contains("JVM"), "no JAVA|JVM samples"); - assertFalse(modes.contains("UNKNOWN"), "UNKNOWN wallclock samples on HotSpot"); - } else { - assertTrue(modes.contains("UNKNOWN"), "no UNKNOWN samples"); - } - - // context filtering should prevent these - assertFalse(states.contains("NEW")); - assertFalse(states.contains("TERMINATED")); - double totalWeight = method1Weight + method2Weight + method3Weight + unattributedWeight; - // method1 has ~50% self time, 50% calling method2 - assertWeight("method1Impl", totalWeight, method1Weight, 0.33); - // method2 has as much self time as method1 - assertWeight("method2Impl", totalWeight, method2Weight, 0.33); - // method3 has as much self time as method1, and should account for half the executor's thread's time - assertWeight("method3Impl", totalWeight, method3Weight, 0.33); - Map debugCounters = profiler.getDebugCounters(); - // these are here to verify these counters produce reasonable values so they can be used for memory leak detection - assertInRange(debugCounters.get("calltrace_storage_traces"), 1, 100); - assertInRange(debugCounters.get("calltrace_storage_bytes"), 1024, 8 * 1024 * 1024); - // this allocator is only used for calltrace storage and eagerly allocates chunks of 8MiB - assertEquals(0, debugCounters.get("linear_allocator_bytes")); - assertEquals(0, debugCounters.get("linear_allocator_chunks")); - assertInRange(debugCounters.get("thread_ids_count"), 1, 100); - assertInRange(debugCounters.get("thread_names_count"), 1, 100); - } - - private void assertWeight(String name, double total, long weight, double expected) { - assertTrue(Math.abs(weight / total - expected) < 0.2, String.format("expect %f weight for %s but have %f", expected, name, weight / total)); - } - - - public void method1(int id) throws ExecutionException, InterruptedException { - try (Tracing.Context context = Tracing.newContext(() -> id, profiler)) { - method1Impl(id, context); - } - } - - public void method1Impl(int id, Tracing.Context context) throws ExecutionException, InterruptedException { - sleep(10); - Object monitor = new Object(); - Future wait = executor.submit(() -> method3(id, monitor)); - method2(id, monitor); - synchronized (monitor) { - monitor.wait(10); - } - wait.get(); - record("method1Impl", context); - } - - public void method2(long id, Object monitor) { - synchronized (monitor) { - try (Tracing.Context context = Tracing.newContext(() -> id + 1, profiler)) { - method2Impl(context); - monitor.notify(); - } - } - } - - public void method2Impl(Tracing.Context context) { - sleep(10); - record("method2Impl", context); - } - - public void method3(long id, Object monitor) { - synchronized (monitor) { - try (Tracing.Context context = Tracing.newContext(() -> id + 2, profiler)) { - method3Impl(context); - monitor.notify(); - } - } - } - - public void method3Impl(Tracing.Context context) { - sleep(10); - record("method3Impl", context); - } - - - private void record(String methodName, Tracing.Context context) { - methodsToSpanIds.computeIfAbsent(methodName, k -> new CopyOnWriteArrayList<>()) - .add(context.getSpanId()); - } - - - private void sleep(long millis) { - try { - Thread.sleep(millis); - } catch (InterruptedException e) { - Thread.currentThread().interrupt(); - } + base.before(); } @Override protected void after() throws InterruptedException { - executor.shutdownNow(); - executor.awaitTermination(30, TimeUnit.SECONDS); + base.after(); + } + + @RetryTest(5) + @TestTemplate + @ValueSource(strings = {"fp", "dwarf", "vm", "vmx"}) + public void test(@CStack String cstack) throws ExecutionException, InterruptedException { + // on aarch64 and JDK < 17 the vmstructs unwinding for wallclock is extremely unreliable + // ; perhaps due to something missing in the unwinder but until we figure it out we will just not run the tests in CI + assumeTrue(!isInCI() || !Platform.isAarch64() || !cstack.startsWith("vm") || Platform.isJavaVersionAtLeast(17)); + // TODO: investigate why this test fails on musl + // on musl the missing fp unwinding makes the wallclock tests unreliable + assumeTrue(!Platform.isMusl() || !cstack.startsWith("vm")); + base.test(this); } @Override diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedContextWallClockTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedContextWallClockTest.java index 2c4a6777..57392451 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedContextWallClockTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedContextWallClockTest.java @@ -1,9 +1,30 @@ package com.datadoghq.profiler.wallclock; -public class JvmtiBasedContextWallClockTest extends ContextWallClockTest { +import com.datadoghq.profiler.AbstractProfilerTest; +import org.junitpioneer.jupiter.RetryingTest; + +import java.util.concurrent.ExecutionException; + +public class JvmtiBasedContextWallClockTest extends AbstractProfilerTest { + private final BaseContextWallClockTest base = new BaseContextWallClockTest(() -> profiler); + + @Override + protected void before() { + base.before(); + } + + @Override + protected void after() throws InterruptedException { + base.after(); + } + + @RetryingTest(5) + public void test() throws ExecutionException, InterruptedException { + base.test(this); + } @Override protected String getProfilerCommand() { - return super.getProfilerCommand() + ";wallsampler=jvmti"; + return "wall=~1ms,filter=0,loglevel=warn;wallsampler=jvmti"; } } \ No newline at end of file diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/SmokeWallTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/SmokeWallTest.java new file mode 100644 index 00000000..eb0078b8 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/SmokeWallTest.java @@ -0,0 +1,63 @@ +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.CStackAwareAbstractProfilerTest; +import com.datadoghq.profiler.Platform; +import com.datadoghq.profiler.cpu.ProfiledCode; +import com.datadoghq.profiler.junit.CStack; +import com.datadoghq.profiler.junit.RetryTest; +import org.junit.jupiter.api.TestTemplate; +import org.junit.jupiter.params.provider.ValueSource; +import org.openjdk.jmc.common.item.IItem; +import org.openjdk.jmc.common.item.IItemCollection; +import org.openjdk.jmc.common.item.IItemIterable; +import org.openjdk.jmc.common.item.IMemberAccessor; +import org.openjdk.jmc.flightrecorder.jdk.JdkAttributes; + +import java.util.concurrent.ExecutionException; + +import static org.junit.jupiter.api.Assertions.assertFalse; + +public class SmokeWallTest extends CStackAwareAbstractProfilerTest { + private ProfiledCode profiledCode; + + public SmokeWallTest(@CStack String cstack) { + super(cstack); + } + + @Override + protected void before() { + profiledCode = new ProfiledCode(profiler); + } + + @RetryTest(10) + @TestTemplate + @ValueSource(strings = {"fp", "dwarf", "vm", "vmx"}) + public void test(@CStack String cstack) throws ExecutionException, InterruptedException { + for (int i = 0, id = 1; i < 100; i++, id += 3) { + profiledCode.method1(id); + } + stopProfiler(); + + verifyCStackSettings(); + + IItemCollection events = verifyEvents("datadog.MethodSample"); + + for (IItemIterable cpuSamples : events) { + IMemberAccessor frameAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(cpuSamples.getType()); + for (IItem sample : cpuSamples) { + String stackTrace = frameAccessor.getMember(sample); + assertFalse(stackTrace.contains("jvmtiError")); + } + } + } + + @Override + protected void after() throws Exception { + profiledCode.close(); + } + + @Override + protected String getProfilerCommand() { + return "wall=1ms"; + } +}