From afdb48e2f97dd3e0c9f17ecb35b8674c343e995c Mon Sep 17 00:00:00 2001 From: Paul Fournillon Date: Thu, 15 Oct 2026 09:20:07 +0200 Subject: [PATCH 1/6] feat(wallclock): add paired TaskBlock API with generation-based owned-block tracking --- ddprof-lib/src/main/cpp/counters.h | 13 +- ddprof-lib/src/main/cpp/event.h | 23 +- ddprof-lib/src/main/cpp/flightRecorder.cpp | 32 +- ddprof-lib/src/main/cpp/flightRecorder.h | 2 + ddprof-lib/src/main/cpp/javaApi.cpp | 157 ++++--- ddprof-lib/src/main/cpp/jfrMetadata.cpp | 18 +- ddprof-lib/src/main/cpp/jfrMetadata.h | 1 + ddprof-lib/src/main/cpp/jvmSupport.cpp | 25 +- ddprof-lib/src/main/cpp/jvmSupport.h | 4 + ddprof-lib/src/main/cpp/profiler.cpp | 220 ++++++++-- ddprof-lib/src/main/cpp/profiler.h | 53 +++ ddprof-lib/src/main/cpp/taskBlockRecorder.cpp | 81 ++++ ddprof-lib/src/main/cpp/taskBlockRecorder.h | 98 +++++ ddprof-lib/src/main/cpp/threadFilter.cpp | 82 +++- ddprof-lib/src/main/cpp/threadFilter.h | 17 + ddprof-lib/src/main/cpp/threadLocalData.h | 24 +- ddprof-lib/src/main/cpp/threadState.h | 2 +- ddprof-lib/src/main/cpp/wallClock.cpp | 87 ++-- ddprof-lib/src/main/cpp/wallClock.h | 2 +- .../src/main/cpp/wallClockBlockTracker.cpp | 145 +++++-- .../src/main/cpp/wallClockBlockTracker.h | 245 +++++++---- ddprof-lib/src/main/cpp/wallClockCounters.h | 12 +- .../com/datadoghq/profiler/JavaProfiler.java | 65 ++- ddprof-lib/src/test/cpp/jvmSupport_ut.cpp | 186 ++++++++ ddprof-lib/src/test/cpp/park_state_ut.cpp | 60 +-- .../src/test/cpp/taskBlockRecorder_ut.cpp | 299 +++++++++++++ ddprof-lib/src/test/cpp/threadFilter_ut.cpp | 81 ++-- .../src/test/cpp/wallClockBlockRestart_ut.cpp | 12 +- .../src/test/cpp/wallClockBlockTracker_ut.cpp | 405 ++++++++++++++++-- .../src/test/cpp/wallClockCounters_ut.cpp | 18 +- .../src/test/fuzz/fuzz_threadFilter.cpp | 13 +- .../profiler/JavaProfilerApiSurfaceTest.java | 14 +- .../profiler/ProfilerOwnedBlockHooks.java | 13 +- .../ConcurrentOwnedBlockChurnTest.java | 4 +- .../JavaProfilerTaskBlockApiTest.java | 279 ++++++++++++ .../JavaProfilerTaskBlockDisabledTest.java | 24 ++ .../JavaProfilerTaskBlockLightweightTest.java | 85 ++++ ...rofilerTaskBlockPreExistingThreadTest.java | 76 ++++ .../wallclock/JvmtiBasedPrecheckTest.java | 4 +- .../wallclock/PrecheckEfficiencyTest.java | 37 +- .../profiler/wallclock/PrecheckTest.java | 108 +++-- .../wallclock/TaskBlockAssertions.java | 94 ++++ .../wallclock/UnfilteredWallPrecheckTest.java | 29 +- .../WallclockMitigationsCombinedTest.java | 25 +- 44 files changed, 2726 insertions(+), 548 deletions(-) create mode 100644 ddprof-lib/src/main/cpp/taskBlockRecorder.cpp create mode 100644 ddprof-lib/src/main/cpp/taskBlockRecorder.h create mode 100644 ddprof-lib/src/test/cpp/taskBlockRecorder_ut.cpp create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockApiTest.java create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockDisabledTest.java create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockLightweightTest.java create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockPreExistingThreadTest.java create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/TaskBlockAssertions.java diff --git a/ddprof-lib/src/main/cpp/counters.h b/ddprof-lib/src/main/cpp/counters.h index 6f7015f9cf..b0f98e3ae4 100644 --- a/ddprof-lib/src/main/cpp/counters.h +++ b/ddprof-lib/src/main/cpp/counters.h @@ -79,6 +79,8 @@ X(THREAD_REGISTRY_INDEX_FAILURES, "thread_registry_index_failures") \ X(THREAD_REGISTRY_CONTEXT_RESET_RACE_DETECTED, "thread_registry_context_reset_race_detected") \ X(THREAD_REGISTRY_HOOK_REREGISTRATION, "thread_registry_hook_reregistration") \ + X(THREAD_REGISTRY_BLOCK_GENERATION_SATURATED, "thread_registry_block_generation_saturated") \ + X(THREAD_REGISTRY_UNREGISTER_ACTIVE_BLOCK_RUN, "thread_registry_unregister_active_block_run") \ X(JMETHODID_SKIPPED, "jmethodid_skipped_count") \ X(CODECACHE_NATIVE_SIZE_BYTES, "codecache_native_size_bytes") \ X(CODECACHE_NATIVE_COUNT, "native_codecache_count") \ @@ -88,13 +90,22 @@ 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(WC_SIGNAL_SUPPRESSED_SAMPLED_RUN, "wc_signals_suppressed_sampled_run") \ X(WC_PRECHECK_REGISTRY_LOOKUPS, "wc_precheck_registry_lookups") \ X(WC_PRECHECK_CANDIDATES_REJECTED, "wc_precheck_candidates_rejected") \ X(WC_PRECHECK_LOOKUP_BUDGET_EXHAUSTED, "wc_precheck_lookup_budget_exhausted") \ + X(WC_SIGNAL_SUPPRESSED_OWNED_BLOCK, "wc_signals_suppressed_owned_block") \ X(WC_UNOWNED_BLOCKED_SUPPRESSED, "wc_unowned_blocked_suppressed") \ X(WC_UNOWNED_BLOCKED_RECORDED, "wc_unowned_blocked_recorded") \ X(WC_SIGNAL_QUEUE_FULL, "wc_signals_queue_full") \ + X(TASK_BLOCK_EMITTED, "task_block_emitted") \ + X(TASK_BLOCK_SKIPPED_TRACE_CONTEXT, "task_block_skipped_trace_context") \ + X(TASK_BLOCK_SKIPPED_CONTEXT_WINDOW, "task_block_skipped_context_window") \ + X(TASK_BLOCK_SKIPPED_TOO_SHORT, "task_block_skipped_too_short") \ + X(TASK_BLOCK_STACK_CAPTURE_FAILED, "task_block_stack_capture_failed") \ + X(TASK_BLOCK_RECORD_FAILED, "task_block_record_failed") \ + X(TASK_BLOCK_DROPPED_ROTATION, "task_block_dropped_rotation") \ + X(TASK_BLOCK_SKIPPED_THREAD_MISMATCH, "task_block_skipped_thread_mismatch") \ + X(TASK_BLOCK_ROTATION_TIMEOUT, "task_block_rotation_timeout") \ X(UNWINDING_TIME_ASYNC, "unwinding_ticks_async") \ X(UNWINDING_TIME_JVMTI, "unwinding_ticks_jvmti") \ X(CALLTRACE_STORAGE_DROPPED, "calltrace_storage_dropped_traces") \ diff --git a/ddprof-lib/src/main/cpp/event.h b/ddprof-lib/src/main/cpp/event.h index 1e8dc91b5e..215a7a2fd9 100644 --- a/ddprof-lib/src/main/cpp/event.h +++ b/ddprof-lib/src/main/cpp/event.h @@ -60,11 +60,10 @@ class ExecutionEvent : public Event { OSThreadState _thread_state; ExecutionMode _execution_mode; u64 _weight; - u32 _call_trace_id; ExecutionEvent() : Event(), _thread_state(OSThreadState::RUNNABLE), _execution_mode(ExecutionMode::UNKNOWN), - _weight(1), _call_trace_id(0) {} + _weight(1) {} }; class AllocEvent : public Event { @@ -210,13 +209,13 @@ class WallClockEpochEvent { u32 _num_failed_samples; u32 _num_exited_threads; u32 _num_permission_denied; - u64 _num_suppressed_sampled_run; + u64 _num_suppressed_owned_block; WallClockEpochEvent(u64 start_time) : _dirty(false), _start_time(start_time), _duration_millis(0), _num_samplable_threads(0), _num_successful_samples(0), _num_failed_samples(0), _num_exited_threads(0), - _num_permission_denied(0), _num_suppressed_sampled_run(0) {} + _num_permission_denied(0), _num_suppressed_owned_block(0) {} bool hasChanged() { return _dirty; } @@ -255,10 +254,10 @@ class WallClockEpochEvent { } } - void addNumSuppressedSampledRun(u64 n) { + void addNumSuppressedOwnedBlock(u64 n) { if (n > 0) { _dirty = true; - _num_suppressed_sampled_run += n; + _num_suppressed_owned_block += n; } } @@ -269,7 +268,7 @@ class WallClockEpochEvent { void newEpoch(u64 start_time) { _dirty = false; _start_time = start_time; - _num_suppressed_sampled_run = 0; + _num_suppressed_owned_block = 0; } }; @@ -294,4 +293,14 @@ typedef struct QueueTimeEvent { u32 _queueLength; } QueueTimeEvent; +typedef struct TaskBlockEvent { + u64 _start; + u64 _end; + u64 _blocker; + u64 _unblockingSpanId; + Context _ctx; + u64 _callTraceId; + OSThreadState _observedBlockingState; +} TaskBlockEvent; + #endif // _EVENT_H diff --git a/ddprof-lib/src/main/cpp/flightRecorder.cpp b/ddprof-lib/src/main/cpp/flightRecorder.cpp index e5c432603c..9f572c6bf3 100644 --- a/ddprof-lib/src/main/cpp/flightRecorder.cpp +++ b/ddprof-lib/src/main/cpp/flightRecorder.cpp @@ -2312,6 +2312,21 @@ void Recording::recordMethodSample(Buffer *buf, int tid, u64 call_trace_id, flushIfNeeded(buf); } +void Recording::recordTaskBlock(Buffer *buf, int tid, TaskBlockEvent *event) { + int start = buf->skip(1); + buf->putVar64(T_TASK_BLOCK); + buf->putVar64(event->_start); + buf->putVar64(event->_end - event->_start); + buf->putVar64(tid); + buf->putVar64(event->_blocker); + buf->putVar64(event->_unblockingSpanId); + buf->putVar64(event->_callTraceId); + buf->put8(static_cast(event->_observedBlockingState)); + writeContextSnapshot(buf, event->_ctx); + writeEventSizePrefix(buf, start); + flushIfNeeded(buf); +} + void Recording::recordWallClockEpoch(Buffer *buf, WallClockEpochEvent *event) { int start = buf->skip(1); buf->putVar64(T_WALLCLOCK_SAMPLE_EPOCH); @@ -2322,7 +2337,7 @@ void Recording::recordWallClockEpoch(Buffer *buf, WallClockEpochEvent *event) { buf->putVar64(event->_num_failed_samples); buf->putVar64(event->_num_exited_threads); buf->putVar64(event->_num_permission_denied); - buf->putVar64(event->_num_suppressed_sampled_run); + buf->putVar64(event->_num_suppressed_owned_block); writeEventSizePrefix(buf, start); flushIfNeeded(buf); } @@ -2731,6 +2746,21 @@ void FlightRecorder::recordQueueTime(int lock_index, int tid, } } +bool FlightRecorder::recordTaskBlock(int lock_index, int tid, + TaskBlockEvent *event) { + OptionalSharedLockGuard locker(&_rec_lock); + if (locker.ownsLock()) { + Recording* rec = _rec; + if (rec != nullptr) { + Buffer *buf = rec->buffer(lock_index); + rec->addThread(lock_index, tid); + rec->recordTaskBlock(buf, tid, event); + return true; + } + } + return false; +} + void FlightRecorder::recordDatadogSetting(int lock_index, int length, const char *name, const char *value, const char *unit) { diff --git a/ddprof-lib/src/main/cpp/flightRecorder.h b/ddprof-lib/src/main/cpp/flightRecorder.h index f660e85c3b..a47b0813ed 100644 --- a/ddprof-lib/src/main/cpp/flightRecorder.h +++ b/ddprof-lib/src/main/cpp/flightRecorder.h @@ -426,6 +426,7 @@ class Recording { void recordWallClockEpoch(Buffer *buf, WallClockEpochEvent *event); void recordTraceRoot(Buffer *buf, int tid, TraceRootEvent *event); void recordQueueTime(Buffer *buf, int tid, QueueTimeEvent *event); + void recordTaskBlock(Buffer *buf, int tid, TaskBlockEvent *event); void recordAllocation(RecordingBuffer *buf, int tid, u64 call_trace_id, AllocEvent *event); void recordMallocSample(Buffer *buf, int tid, u64 call_trace_id, @@ -572,6 +573,7 @@ class FlightRecorder { void wallClockEpoch(int lock_index, WallClockEpochEvent *event); void recordTraceRoot(int lock_index, int tid, TraceRootEvent *event); void recordQueueTime(int lock_index, int tid, QueueTimeEvent *event); + bool recordTaskBlock(int lock_index, int tid, TaskBlockEvent *event); bool active() const { return _rec != NULL; } diff --git a/ddprof-lib/src/main/cpp/javaApi.cpp b/ddprof-lib/src/main/cpp/javaApi.cpp index 35cff8b238..496ac75d36 100644 --- a/ddprof-lib/src/main/cpp/javaApi.cpp +++ b/ddprof-lib/src/main/cpp/javaApi.cpp @@ -31,6 +31,7 @@ #include "os.h" #include "otel_process_ctx.h" #include "profiler.h" +#include "taskBlockRecorder.h" #include "threadLocalData.inline.h" #include "tsc.h" #include "vmEntry.h" @@ -163,44 +164,16 @@ Java_com_datadoghq_profiler_JavaProfiler_getSamples(JNIEnv *env, } // some duplication between add and remove, though we want to avoid having an extra branch in the hot path - -static ThreadFilter::SlotID ensureCurrentThreadFilterSlot( - ThreadFilter *thread_filter, ProfiledThread *current) { - int tid = current->tid(); - if (unlikely(tid < 0)) { - return -1; - } - - ThreadFilter::SlotID slot_id = current->filterSlotId(); - if (likely(slot_id >= 0)) { - if (likely(thread_filter->activeSlotForId(slot_id, tid) != nullptr)) { - return slot_id; - } - current->setFilterSlotId(-1); - } - - // Threads that existed before the recording started (and so never received - // a ThreadStart callback) bind their slot lazily here. If the tid is already - // indexed, registerThread(tid) returns that existing slot. - // - // This is the only place the filterThreadAdd0 (JavaCritical), parkEnter0 - // and blockEnter0 hooks can block on _registry_lock. It's bounded to at - // most once per thread lifetime (cold TLS) plus once per recording-epoch - // transition this thread observes (stale cached slot) - not a per-call cost. - // A thread that cannot get a slot because the registry is full retries here - // on every call, but registerThread() rejects it without taking the lock. - // THREAD_REGISTRY_HOOK_REREGISTRATION counts every attempt, including those - // lock-free rejections (tracked separately by - // THREAD_REGISTRY_CAPACITY_EXHAUSTED). If it fires per call while - // THREAD_REGISTRY_CAPACITY_EXHAUSTED stays flat, the "provably rare" - // assumption has broken and these hooks should be revisited. - Counters::increment(THREAD_REGISTRY_HOOK_REREGISTRATION); - slot_id = thread_filter->registerThread(tid); - if (slot_id >= 0) { - current->setFilterSlotId(slot_id); - } - return slot_id; -} +// +// Threads that existed before the recording started (and so never received a +// ThreadStart callback) bind their slot lazily on first use. Call sites below +// use ThreadFilter::ensureCurrentThreadSlot(), which also self-heals a cached +// slot that went stale (e.g. an unfiltered recording restart changed the +// recording epoch) by re-deriving it through registerThread() - the only place the +// filterThreadAdd0 (JavaCritical), parkEnter0, blockEnter0 and beginTaskBlock0 +// hooks can block on _registry_lock. A thread that cannot get a slot because +// the registry is full retries on every call, but registerThread() rejects it +// without taking the lock. // JavaCritical is faster JNI, but more restrictive - parameters and return value have to be // primitives or arrays of primitive types. @@ -223,14 +196,14 @@ JavaCritical_com_datadoghq_profiler_JavaProfiler_filterThreadAdd0() { return; } - int slot_id = ensureCurrentThreadFilterSlot(thread_filter, current); + int slot_id = thread_filter->ensureCurrentThreadSlot(current); if (unlikely(slot_id < 0)) { return; // Failed to register thread } if (unlikely(!thread_filter->add(tid, slot_id))) { // The cached slot_id no longer carries this thread's tid. // Clear the cache so the next filterThreadAdd0()/parkEnter0()/blockEnter0() - // call re-runs ensureCurrentThreadFilterSlot()'s registerThread() path + // call re-runs ensureCurrentThreadSlot()'s registerThread() path // instead of leaving this thread permanently outside the context window. current->setFilterSlotId(-1); } @@ -439,23 +412,24 @@ Java_com_datadoghq_profiler_JavaProfiler_recordQueueEnd0( Profiler::instance()->recordQueueTime(tid, &event); } -extern "C" DLLEXPORT void JNICALL +extern "C" DLLEXPORT jboolean JNICALL Java_com_datadoghq_profiler_JavaProfiler_parkEnter0(JNIEnv *env, jclass unused) { ProfiledThread *current = ProfiledThread::initCurrentThreadSignalSafe(); if (current == nullptr) { - return; + return JNI_FALSE; } bool first_park = current->parkEnter(); ThreadFilter *tf = Profiler::instance()->threadFilter(); if (first_park && tf->registryActive()) { - ThreadFilter::SlotID slot_id = ensureCurrentThreadFilterSlot(tf, current); + ThreadFilter::SlotID slot_id = tf->ensureCurrentThreadSlot(current); if (slot_id >= 0) { WallClockBlockTracker *tracker = Profiler::instance()->blockTracker(); current->setParkBlockToken( tracker->enterBlockedRun(tf, slot_id, OSThreadState::CONDVAR_WAIT)); } } + return first_park ? JNI_TRUE : JNI_FALSE; } extern "C" DLLEXPORT void JNICALL @@ -491,6 +465,20 @@ static bool decodeJavaBlockState(jint state, OSThreadState &decoded) { return false; } +// beginTaskBlock0/endTaskBlock0 accept an explicit jthread for stack-walking and +// classification; verify it actually identifies the calling thread, since the two +// could otherwise diverge (e.g. a stale or mismatched jthread handle). +static bool isCurrentJniThread(JNIEnv* env, jthread thread) { + if (thread == nullptr) return false; + jthread current_thread = nullptr; + if (VM::jvmti()->GetCurrentThread(¤t_thread) != JVMTI_ERROR_NONE) { + return false; + } + bool same = env->IsSameObject(thread, current_thread); + env->DeleteLocalRef(current_thread); + return same; +} + extern "C" DLLEXPORT jlong JNICALL Java_com_datadoghq_profiler_JavaProfiler_blockEnter0( JNIEnv *env, jclass unused, jint state) { @@ -498,20 +486,25 @@ Java_com_datadoghq_profiler_JavaProfiler_blockEnter0( if (current == nullptr) { return 0; } - OSThreadState decoded; if (!decodeJavaBlockState(state, decoded)) { return 0; } - ThreadFilter *tf = Profiler::instance()->threadFilter(); - if (!tf->registryActive()) { + u64 span_id = 0, root_span_id = 0; + ContextApi::get(span_id, root_span_id); + if (span_id != 0) { + return 0; + } + Profiler *profiler = Profiler::instance(); + ThreadFilter *tf = profiler->threadFilter(); + if (!profiler->taskBlockEnabled() && !tf->registryActive()) { return 0; } - ThreadFilter::SlotID slot_id = ensureCurrentThreadFilterSlot(tf, current); + ThreadFilter::SlotID slot_id = tf->ensureCurrentThreadSlot(current); if (slot_id < 0) { return 0; } - WallClockBlockTracker *tracker = Profiler::instance()->blockTracker(); + WallClockBlockTracker *tracker = profiler->blockTracker(); return static_cast(tracker->enterBlockedRun(tf, slot_id, decoded)); } @@ -539,6 +532,74 @@ Java_com_datadoghq_profiler_JavaProfiler_blockExit0( } } +extern "C" DLLEXPORT jlong JNICALL +Java_com_datadoghq_profiler_JavaProfiler_beginTaskBlock0( + JNIEnv *env, jclass unused, jthread thread) { + ProfiledThread *current = ProfiledThread::initCurrentThreadSignalSafe(); + Profiler *profiler = Profiler::instance(); + if (current == nullptr || !profiler->isRunning() || + !profiler->taskBlockEnabled()) { + return 0; + } + ThreadFilter *tf = profiler->threadFilter(); + if (!tf->unfilteredWallTrackingActive()) return 0; + if (!isCurrentJniThread(env, thread)) { + Counters::increment(TASK_BLOCK_SKIPPED_THREAD_MISMATCH); + return 0; + } + if (!JVMSupport::isPlatformThread(env, thread)) { + return 0; + } + ThreadFilter::SlotID slot_id = tf->ensureCurrentThreadSlot(current); + if (slot_id < 0) return 0; + + Context context = ContextApi::snapshot(); + if (context.spanId != 0) { + Counters::increment(TASK_BLOCK_SKIPPED_TRACE_CONTEXT); + return 0; + } + WallClockBlockTracker *tracker = profiler->blockTracker(); + u64 token = tracker->enterBlockedRun( + tf, slot_id, OSThreadState::SLEEPING, BlockRunOwner::TASK_BLOCK); + if (!current->taskBlockEnter(token, TSC::ticks(), context)) { + if (token != 0) { + tracker->exitBlockedRun(slot_id, + WallClockBlockTracker::tokenGeneration(token)); + } + return 0; + } + return static_cast(token); +} + +extern "C" DLLEXPORT jboolean JNICALL +Java_com_datadoghq_profiler_JavaProfiler_endTaskBlock0( + JNIEnv *env, jclass unused, jthread thread, jlong token, jlong blocker, + jlong unblockingSpanId) { + u64 block_token = static_cast(token); + ThreadFilter::SlotID slot_id = -1; + u64 generation = 0; + if (!WallClockBlockTracker::decodeBlockRunToken(block_token, slot_id, + generation)) { + return JNI_FALSE; + } + if (!isCurrentJniThread(env, thread)) { + Counters::increment(TASK_BLOCK_SKIPPED_THREAD_MISMATCH); + return JNI_FALSE; + } + if (!JVMSupport::isPlatformThread(env, thread)) { + return JNI_FALSE; + } + ProfiledThread *current = ProfiledThread::initCurrentThreadSignalSafe(); + if (current == nullptr) return JNI_FALSE; + + Profiler *profiler = Profiler::instance(); + bool recorded = recordTaskBlockAtExit( + current, profiler->threadFilter(), profiler->blockTracker(), thread, 1, + block_token, static_cast(blocker), + static_cast(unblockingSpanId)); + return recorded ? JNI_TRUE : JNI_FALSE; +} + extern "C" DLLEXPORT jlong JNICALL Java_com_datadoghq_profiler_JavaProfiler_currentTicks0(JNIEnv *env, jclass unused) { diff --git a/ddprof-lib/src/main/cpp/jfrMetadata.cpp b/ddprof-lib/src/main/cpp/jfrMetadata.cpp index 86b0e8ebe7..530ba577ac 100644 --- a/ddprof-lib/src/main/cpp/jfrMetadata.cpp +++ b/ddprof-lib/src/main/cpp/jfrMetadata.cpp @@ -176,8 +176,8 @@ void JfrMetadata::initialize( "Number of Exited Threads Before Handling Signal") << field("numPermissionDenied", T_INT, "Number of Permission Denied Errors") - << field("numSuppressedSampledRun", T_LONG, - "Signals suppressed by the wall-clock once-per-run filter")) + << field("numSuppressedOwnedBlock", T_LONG, + "Signals suppressed for lifecycle-owned blocked intervals")) << (type("datadog.ObjectSample", T_ALLOC, "Allocation sample") << category("Datadog", "Profiling") @@ -261,6 +261,20 @@ void JfrMetadata::initialize( << field("localRootSpanId", T_LONG, "Local Root Span ID") || contextAttributes) + << (type("datadog.TaskBlock", T_TASK_BLOCK, "Task Block") + << category("Datadog") + << field("startTime", T_LONG, "Start Time", F_TIME_TICKS) + << field("duration", T_LONG, "Duration", F_DURATION_TICKS) + << field("eventThread", T_THREAD, "Event Thread", F_CPOOL) + << field("blocker", T_LONG, "Blocker Identity Hash") + << field("unblockingSpanId", T_LONG, "Unblocking Span ID") + << field("stackTrace", T_STACK_TRACE, "Stack Trace", F_CPOOL) + << field("observedBlockingState", T_THREAD_STATE, + "Observed Blocking State", F_CPOOL) + << field("spanId", T_LONG, "Span ID") + << field("localRootSpanId", T_LONG, "Local Root Span ID") || + contextAttributes) + << (type("datadog.HeapUsage", T_HEAP_USAGE, "JVM Heap Usage") << category("Datadog") << field("startTime", T_LONG, "Start Time", F_TIME_TICKS) diff --git a/ddprof-lib/src/main/cpp/jfrMetadata.h b/ddprof-lib/src/main/cpp/jfrMetadata.h index f533e9a41d..c189a62839 100644 --- a/ddprof-lib/src/main/cpp/jfrMetadata.h +++ b/ddprof-lib/src/main/cpp/jfrMetadata.h @@ -87,6 +87,7 @@ enum JfrType { // doc's "no silent truncation" requirement), see jfrMetadata.cpp. T_REFERENCE_CHAIN = 129, T_REFERENCE_CHAIN_ABANDONED = 130, + T_TASK_BLOCK = 131, T_ANNOTATION = 200, T_LABEL = 201, T_CATEGORY = 202, diff --git a/ddprof-lib/src/main/cpp/jvmSupport.cpp b/ddprof-lib/src/main/cpp/jvmSupport.cpp index 4dc2be966e..7e7e38fbca 100644 --- a/ddprof-lib/src/main/cpp/jvmSupport.cpp +++ b/ddprof-lib/src/main/cpp/jvmSupport.cpp @@ -18,16 +18,39 @@ #include +using JniFunction = void (JNICALL*)(); +using IsVirtualThreadFunction = jboolean (JNICALL*)(JNIEnv*, jobject); + +static constexpr jint JNI_VERSION_19_VALUE = 0x00130000; +static constexpr int IS_VIRTUAL_THREAD_INDEX = 234; + +static_assert(sizeof(JniFunction) == sizeof(void*), + "JNI function table entries must be pointer-sized"); volatile JVMSupport::JMethodIDLoadStats JVMSupport::jmethodID_load_state = JVMSupport::No_loaded; Mutex JVMSupport::_initialization_lock; - // This method must be called after JVM has been properly initialized, e.g. after JVMTI::VMinit() // callback. // Currently, there are two paths lead to this call // - JVMTI::VMInit() callback (vmEntry.cpp) // - JavaProfiler.getInstance() via JNI down call - JVM must have been initialized +bool JVMSupport::isPlatformThread(JNIEnv* jni, jthread thread) { + if (jni == nullptr || thread == nullptr) return false; + jint jni_version = jni->GetVersion(); + if (jni_version <= 0) return false; + if (jni_version < JNI_VERSION_19_VALUE) return true; + if (!VM::isHotspot()) return true; + + const JniFunction* functions = + reinterpret_cast(jni->functions); + IsVirtualThreadFunction is_virtual_thread = + reinterpret_cast( + functions[IS_VIRTUAL_THREAD_INDEX]); + return is_virtual_thread != nullptr && + is_virtual_thread(jni, thread) == JNI_FALSE; +} + bool JVMSupport::initialize() { MutexLocker locker(_initialization_lock); diff --git a/ddprof-lib/src/main/cpp/jvmSupport.h b/ddprof-lib/src/main/cpp/jvmSupport.h index 49b8a9193f..cfc427d348 100644 --- a/ddprof-lib/src/main/cpp/jvmSupport.h +++ b/ddprof-lib/src/main/cpp/jvmSupport.h @@ -48,6 +48,10 @@ class JVMSupport { static bool isInitialized(); public: + // Java-owned profiler state is carrier-local and may only be used by platform threads. + // IsVirtualThread was added to the JNI function table in JDK 19. + static bool isPlatformThread(JNIEnv* jni, jthread thread); + // Initialize JVM support - check JVM related resources are available. // Return false if any critical resource is not available, which should // result in disabling profiling. diff --git a/ddprof-lib/src/main/cpp/profiler.cpp b/ddprof-lib/src/main/cpp/profiler.cpp index d08b03c1ec..4f422a77ff 100644 --- a/ddprof-lib/src/main/cpp/profiler.cpp +++ b/ddprof-lib/src/main/cpp/profiler.cpp @@ -38,6 +38,7 @@ #include "stackWalker.h" #include "stackWalker.inline.h" #include "symbols.h" +#include "taskBlockRecorder.h" #include "threadLocalData.inline.h" #include "tsc.h" #include "utils.h" @@ -52,13 +53,16 @@ #include #include #include +#include #include +#include #include #include #include #include #include #include +#include #include // The instance is not deleted on purpose, since profiler structures @@ -175,6 +179,8 @@ int Profiler::registerThread(int tid) { } #ifdef UNIT_TEST static std::atomic g_test_last_unregistered_tid{-1}; +static std::atomic + g_test_task_block_record_override{nullptr}; int Profiler::lastUnregisteredTidForTest() { return g_test_last_unregistered_tid.load(std::memory_order_relaxed); @@ -182,6 +188,11 @@ int Profiler::lastUnregisteredTidForTest() { void Profiler::resetUnregisterObservableForTest() { g_test_last_unregistered_tid.store(-1, std::memory_order_relaxed); } + +void Profiler::setTaskBlockRecordOverrideForTest( + TaskBlockRecordOverride override) { + g_test_task_block_record_override.store(override, std::memory_order_release); +} #endif void Profiler::unregisterThread(int tid) { @@ -571,6 +582,34 @@ int Profiler::convertNativeTrace(int native_frames, const void **callchain, return depth; } +int Profiler::captureJVMTIFrames(jthread thread, int start_depth, + CallTraceBuffer* buffer) { + ASGCT_CallFrame *frames = buffer->_asgct_frames; + jvmtiFrameInfo *jvmti_frames = buffer->_jvmti_frames; + jint num_frames = 0; + if (VM::jvmti()->GetStackTrace(thread, start_depth, _max_stack_depth, + jvmti_frames, &num_frames) != JVMTI_ERROR_NONE || + num_frames <= 0) { + return 0; + } + copyJvmtiFrames(frames, jvmti_frames, num_frames); + // See recordJVMTISample's original comment: GetStackTrace on a JDK21+ virtual + // thread returns only the VT's logical stack, stopping at the continuation + // boundary. Append a synthetic root frame so the UI doesn't report it as + // "Missing Frames". + if (VM::isHotspot() && VM::hotspot_version() >= 21 && + num_frames < _max_stack_depth) { + VMThread* carrier = VMThread::current(); + if (carrier != nullptr && carrier->isCarryingVirtualThread()) { + frames[num_frames].bci = BCI_NATIVE_FRAME; + frames[num_frames].method_id = (jmethodID) "JVM Continuation"; + LP64_ONLY(frames[num_frames].padding = 0;) + num_frames++; + } + } + return num_frames; +} + u64 Profiler::recordJVMTISample(u64 counter, int tid, jthread thread, jint event_type, Event *event, bool deferred) { // Called from non-signal based sampler ProfiledThread* prof_thread = ProfiledThread::initCurrentThreadSignalSafe(); @@ -606,37 +645,8 @@ u64 Profiler::recordJVMTISample(u64 counter, int tid, jthread thread, jint event #ifdef COUNTERS u64 startTime = TSC::ticks(); #endif // COUNTERS - ASGCT_CallFrame *frames = buf->_asgct_frames; - jvmtiFrameInfo *jvmti_frames = buf->_jvmti_frames; - - int num_frames = 0; - - if (VM::jvmti()->GetStackTrace(thread, 0, _max_stack_depth, jvmti_frames, &num_frames) == JVMTI_ERROR_NONE && num_frames > 0) { - // Convert to AsyncGetCallTrace format. - // Note: jvmti_frames and frames may overlap. - copyJvmtiFrames(frames, jvmti_frames, num_frames); - // On JDK 21+, GetStackTrace on a virtual thread returns only the VT's - // logical stack; it stops at the continuation boundary and never includes - // carrier-thread frames. Without a synthetic root the trace appears - // truncated to the UI backend, which attributes it to "Missing Frames". - // Detect the VT case via JavaThread::_cont_entry being non-null on the - // carrier. This field is in gHotSpotVMStructs on all JDK 21+ builds so - // isCarryingVirtualThread() works regardless of JDK version. Append a - // synthetic "JVM Continuation" root frame to mark the boundary - // explicitly, matching the behaviour of walkVM without carrier_frames. - if (VM::isHotspot() && VM::hotspot_version() >= 21 && - num_frames < _max_stack_depth) { - VMThread* carrier = VMThread::current(); - if (carrier != nullptr && carrier->isCarryingVirtualThread()) { - frames[num_frames].bci = BCI_NATIVE_FRAME; - frames[num_frames].method_id = (jmethodID) "JVM Continuation"; - LP64_ONLY(frames[num_frames].padding = 0;) - num_frames++; - } - } - } - - call_trace_id = _call_trace_storage.put(num_frames, frames, false, counter); + int num_frames = captureJVMTIFrames(thread, 0, buf); + call_trace_id = _call_trace_storage.put(num_frames, buf->_asgct_frames, false, counter); #ifdef COUNTERS u64 duration = TSC::ticks() - startTime; if (duration > 0) { @@ -815,6 +825,125 @@ void Profiler::recordQueueTime(int tid, QueueTimeEvent *event) { _locks[lock_index].unlock(); } +Profiler::TaskBlockRecordResult Profiler::recordTaskBlock( + int tid, jthread thread, int start_depth, TaskBlockEvent *event) { +#ifdef UNIT_TEST + TaskBlockRecordOverride override = + g_test_task_block_record_override.load(std::memory_order_acquire); + if (override != nullptr) { + return override(tid, thread, start_depth, event); + } +#endif + CriticalSection cs; + u32 lock_index = getLockIndex(tid); + if (!_locks[lock_index].tryLock() && + !_locks[lock_index = (lock_index + 1) % CONCURRENCY_LEVEL].tryLock() && + !_locks[lock_index = (lock_index + 2) % CONCURRENCY_LEVEL].tryLock()) { + return TaskBlockRecordResult::RECORD_FAILED; + } + + // Lightweight recordings intentionally encode an absent stack trace as + // constant-pool ID 0, as the regular CPU and wall-clock sample paths do. + if (!_omit_stacktraces) { + if (_max_stack_depth <= 0 || _calltrace_buffer[lock_index] == nullptr) { + _locks[lock_index].unlock(); + return TaskBlockRecordResult::STACK_CAPTURE_FAILED; + } + + CallTraceBuffer *buffer = _calltrace_buffer[lock_index]; +#ifdef COUNTERS + u64 stack_start = TSC::ticks(); +#endif + int num_frames = captureJVMTIFrames(thread, start_depth, buffer); + if (num_frames <= 0) { + _locks[lock_index].unlock(); + return TaskBlockRecordResult::STACK_CAPTURE_FAILED; + } + + u64 call_trace_id = + _call_trace_storage.put(num_frames, buffer->_asgct_frames, false, 1); +#ifdef COUNTERS + u64 stack_duration = TSC::ticks() - stack_start; + if (stack_duration > 0) { + Counters::increment(UNWINDING_TIME_JVMTI, stack_duration); + } +#endif + if (call_trace_id == 0) { + _locks[lock_index].unlock(); + return TaskBlockRecordResult::STACK_CAPTURE_FAILED; + } + + event->_callTraceId = call_trace_id; + } + bool recorded = _jfr.recordTaskBlock(lock_index, tid, event); + _locks[lock_index].unlock(); + return recorded ? TaskBlockRecordResult::RECORDED + : TaskBlockRecordResult::RECORD_FAILED; +} + +bool Profiler::tryEnterTaskBlockActivity() { + if (_task_block_rotation.load(std::memory_order_acquire)) return false; + _task_block_inflight.fetch_add(1, std::memory_order_acq_rel); + if (_task_block_rotation.load(std::memory_order_acquire)) { + _task_block_inflight.fetch_sub(1, std::memory_order_acq_rel); + return false; + } + return true; +} + +void Profiler::leaveTaskBlockActivity() { + _task_block_inflight.fetch_sub(1, std::memory_order_release); +} + +bool Profiler::beginTaskBlockRotation() { + static const long TASK_BLOCK_ROTATION_TIMEOUT_NS = 200000000L; // 200ms, matches SignalInflight::drain() + _task_block_rotation.store(true, std::memory_order_release); + if (_task_block_inflight.load(std::memory_order_acquire) == 0) { + return true; // fast path: nothing in flight + } + + struct timespec deadline; + if (clock_gettime(CLOCK_MONOTONIC, &deadline) != 0) { + Log::error("Profiler::beginTaskBlockRotation: clock_gettime(CLOCK_MONOTONIC) failed " + "(errno=%d). Skipping task-block rotation to avoid a stuck wait.", errno); + _task_block_rotation.store(false, std::memory_order_release); + return false; + } + deadline.tv_nsec += TASK_BLOCK_ROTATION_TIMEOUT_NS; + if (deadline.tv_nsec >= 1000000000L) { + deadline.tv_sec += 1; + deadline.tv_nsec -= 1000000000L; + } + + while (_task_block_inflight.load(std::memory_order_acquire) != 0) { + struct timespec now; + if (clock_gettime(CLOCK_MONOTONIC, &now) != 0) { + Log::error("Profiler::beginTaskBlockRotation: clock_gettime(CLOCK_MONOTONIC) failed " + "(errno=%d). Skipping task-block rotation to avoid a stuck wait.", errno); + _task_block_rotation.store(false, std::memory_order_release); + return false; + } + if (now.tv_sec > deadline.tv_sec || + (now.tv_sec == deadline.tv_sec && now.tv_nsec >= deadline.tv_nsec)) { + u64 remaining = _task_block_inflight.load(std::memory_order_acquire); + Log::error("Profiler::beginTaskBlockRotation: timed out after %ldms waiting for " + "%llu in-flight TaskBlock recording(s). Skipping task-block rotation; " + "this indicates a stuck TaskBlock record path.", + TASK_BLOCK_ROTATION_TIMEOUT_NS / 1000000L, + (unsigned long long)remaining); + Counters::increment(TASK_BLOCK_ROTATION_TIMEOUT); + _task_block_rotation.store(false, std::memory_order_release); + return false; + } + std::this_thread::yield(); + } + return true; +} + +void Profiler::endTaskBlockRotation() { + _task_block_rotation.store(false, std::memory_order_release); +} + void Profiler::recordExternalSample(u64 weight, int tid, int num_frames, ASGCT_CallFrame *frames, bool truncated, jint event_type, Event *event) { @@ -1454,6 +1583,7 @@ Error Profiler::start(Arguments &args, bool reset) { if (error) { return error; } + _task_block_enabled.store(false, std::memory_order_release); // Sanity checks run at most once per process, across start and stop cycles. // Profiler::start() sets sanity_checked to true before it checks @@ -1606,7 +1736,7 @@ Error Profiler::start(Arguments &args, bool reset) { // Set up the sampled thread's TLS in both modes. Context filtering also // pre-registers the caller; unfiltered tracking waits for its first hook. // Retained unfiltered slots remain ineligible until their owner refreshes - // against the new recording epoch in ensureCurrentThreadFilterSlot(). + // against the new recording epoch in ThreadFilter::ensureCurrentThreadSlot(). if (_thread_filter.registryActive()) { ProfiledThread *current = ProfiledThread::initCurrentThreadSignalSafe(); assert(current != nullptr); @@ -1679,6 +1809,7 @@ Error Profiler::start(Arguments &args, bool reset) { _libs->stopRefresher(); return error; } + initializeTaskBlockDurationThreshold(); // Must precede every signal-based engine's start() below: SamplerPerfProbe // (samplerPerf.h) calls OS::nanotime() from inside the signal handler, and @@ -1810,6 +1941,9 @@ Error Profiler::start(Arguments &args, bool reset) { // Paired with drainInflight() on the stop side. _cpu_engine->enableEvents(true); + _task_block_enabled.store( + (activated & EM_WALL) && args._wall_precheck && track_unfiltered_wall, + std::memory_order_release); _state.store(RUNNING, std::memory_order_release); _start_time = time(NULL); __atomic_add_fetch(&_epoch, 1, __ATOMIC_RELAXED); @@ -1834,6 +1968,7 @@ Error Profiler::stop() { if (state() != RUNNING) { return Error("Profiler is not active"); } + _task_block_enabled.store(false, std::memory_order_release); // Order matters: disable engines first so the _enabled check inside signal // handlers will fail for any new signal delivered from now on. drain() then @@ -1851,6 +1986,13 @@ Error Profiler::stop() { return Error("signal handlers did not drain; teardown skipped, retry stop()"); } + // Prevent existing paired intervals from recording during teardown. New + // intervals were disabled above; this also drains endTaskBlock calls that + // already entered their snapshot-and-record activity. + if (!beginTaskBlockRotation()) { + return Error("task-block rotation did not drain; teardown skipped, retry stop()"); + } + // Gate on _activated_mask, not _event_mask: a mixed-success start() can // leave _event_mask requesting an engine whose start() actually failed // (see the "recoverable" error handling in start()), and that engine @@ -1971,6 +2113,7 @@ Error Profiler::stop() { _thread_info.reportCounters(); rotateDictsAndRun([&]{ _jfr.stop(); }); + endTaskBlockRotation(); // Unpatch libraries AFTER JFR serialization completes // Remote symbolication RemoteFrameInfo structs contain pointers to build-ID strings @@ -2101,10 +2244,15 @@ Error Profiler::dump(const char *path, const int length) { // dump (fences ASGCT/JNI writers to CallTraceStorage), then clearStandby()s // the rotated buffers. StringDictionary's RefCountGuard protocol handles // its own writer/reader coordination. - rotateDictsAndRun([&]{ - err = _jfr.dump(path, length); - __atomic_add_fetch(&_epoch, 1, __ATOMIC_SEQ_CST); - }); + if (beginTaskBlockRotation()) { + rotateDictsAndRun([&]{ + err = _jfr.dump(path, length); + __atomic_add_fetch(&_epoch, 1, __ATOMIC_SEQ_CST); + }); + endTaskBlockRotation(); + } else { + err = Error("task-block rotation did not drain; dump skipped"); + } if (err) { TEST_LOG("Profiler::dump _jfr.dump failed: %s", err.message()); } diff --git a/ddprof-lib/src/main/cpp/profiler.h b/ddprof-lib/src/main/cpp/profiler.h index 65ad8cc526..7a7162392c 100644 --- a/ddprof-lib/src/main/cpp/profiler.h +++ b/ddprof-lib/src/main/cpp/profiler.h @@ -147,6 +147,9 @@ class alignas(alignof(SpinLock)) Profiler { // AND referencechains=true - see Profiler::start()). Atomic: also read by // onThreadStart()/onThreadEnd() on JVMTI thread-lifecycle callbacks. std::atomic _reference_chains_active{false}; + std::atomic _task_block_enabled{false}; + std::atomic _task_block_rotation{false}; + std::atomic _task_block_inflight{0}; SpinLock _locks[CONCURRENCY_LEVEL]; CallTraceBuffer *_calltrace_buffer[CONCURRENCY_LEVEL]; @@ -205,6 +208,8 @@ class alignas(alignof(SpinLock)) Profiler { // that turns it into DICTIONARY_DRAIN_TIMEOUTS and a warning. void reportDrainTimeout(const char *what); void unlockAll(); + bool beginTaskBlockRotation(); + void endTaskBlockRotation(); // Rotate all three dictionaries, then run jfr_op under lockAll(). // @@ -274,6 +279,16 @@ class alignas(alignof(SpinLock)) Profiler { _calltrace_buffer[i] = NULL; } _thread_filter.setBlockTracker(&_block_tracker); + + // Protects wall-clock unowned-block fallback tail traces (cached in + // WallClockBlockTracker::BlockState) from being dropped by a chunk + // rotation before flushUnownedBlockedTail() emits them. The tracker lives + // in the Profiler singleton, so this is registered once rather than + // per-recording. + registerLivenessChecker([this](CallTraceIdSet& buffer) { + _block_tracker.collectUnownedBlockedTraceIds( + [&buffer](u64 call_trace_id) { buffer.insert(call_trace_id); }); + }); } static inline Profiler *instance() { @@ -487,6 +502,16 @@ class alignas(alignof(SpinLock)) Profiler { // RequestStackTrace as user_data. bool recordSampleDelegated(void *ucontext, u64 weight, int tid, jint event_type, Event *event); + // Shared by recordJVMTISample()/recordTaskBlock(): performs the JVMTI stack walk for + // `thread` starting at `start_depth`, converts to ASGCT format, and applies the + // JDK21+ virtual-thread continuation-boundary fixup (a real stack, from a carrier's + // perspective, that GetStackTrace on a VT truncates at the continuation boundary). + // Caller must already hold _locks[lock_index] and pass a buffer sized for + // _max_stack_depth frames. Returns the number of frames written into + // buffer->_asgct_frames, or 0 if JVMTI failed to produce any frame — callers differ + // on whether that is a hard failure or a valid empty trace, so this function does + // not decide that, and does not call _call_trace_storage.put() itself. + int captureJVMTIFrames(jthread thread, int start_depth, CallTraceBuffer* buffer); u64 recordJVMTISample(u64 weight, int tid, jthread thread, jint event_type, Event *event, bool deferred); void recordDeferredSample(int tid, u64 call_trace_id, jint event_type, Event *event); void recordExternalSample(u64 weight, int tid, int num_frames, @@ -495,6 +520,25 @@ class alignas(alignof(SpinLock)) Profiler { void recordWallClockEpoch(int tid, WallClockEpochEvent *event); void recordTraceRoot(int tid, TraceRootEvent *event); void recordQueueTime(int tid, QueueTimeEvent *event); + enum class TaskBlockRecordResult { + RECORDED, + STACK_CAPTURE_FAILED, + RECORD_FAILED, + }; + TaskBlockRecordResult recordTaskBlock(int tid, jthread thread, + int start_depth, + TaskBlockEvent *event); +#ifdef UNIT_TEST + using TaskBlockRecordOverride = TaskBlockRecordResult (*)( + int tid, jthread thread, int start_depth, TaskBlockEvent *event); + static void setTaskBlockRecordOverrideForTest( + TaskBlockRecordOverride override); +#endif + bool tryEnterTaskBlockActivity(); + void leaveTaskBlockActivity(); + bool taskBlockEnabled() const { + return _task_block_enabled.load(std::memory_order_acquire); + } void writeLog(LogLevel level, const char *message); void writeLog(LogLevel level, const char *message, size_t len); void writeDatadogProfilerSetting(int tid, int length, const char *name, @@ -522,6 +566,15 @@ class alignas(alignof(SpinLock)) Profiler { // gtest binaries. int resetRecordingStateForTest() { return resetRecordingState(); } + bool beginTaskBlockRotationForTest() { return beginTaskBlockRotation(); } + void endTaskBlockRotationForTest() { endTaskBlockRotation(); } + bool taskBlockRotationActiveForTest() const { + return _task_block_rotation.load(std::memory_order_acquire); + } + int taskBlockInflightForTest() const { + return _task_block_inflight.load(std::memory_order_acquire); + } + // Returns the tid most recently passed to unregisterThread(), or -1 if it // has never been called (or since the last resetUnregisterObservableForTest). // Used by integration tests to assert that cleanup_unregister wired diff --git a/ddprof-lib/src/main/cpp/taskBlockRecorder.cpp b/ddprof-lib/src/main/cpp/taskBlockRecorder.cpp new file mode 100644 index 0000000000..c6adddaa06 --- /dev/null +++ b/ddprof-lib/src/main/cpp/taskBlockRecorder.cpp @@ -0,0 +1,81 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +#include "taskBlockRecorder.h" + +#include + +static const u64 kMinTaskBlockNanos = 1000000; +static std::atomic g_min_task_block_ticks{0}; + +static u64 computeMinTaskBlockTicks() { + return (TSC::frequency() * kMinTaskBlockNanos) / NANOTIME_FREQ; +} + +void initializeTaskBlockDurationThreshold() { + g_min_task_block_ticks.store(computeMinTaskBlockTicks(), std::memory_order_release); +} + +bool exceedsMinTaskBlockDuration(u64 start_ticks, u64 end_ticks) { + u64 min_ticks = g_min_task_block_ticks.load(std::memory_order_acquire); + if (min_ticks == 0) min_ticks = computeMinTaskBlockTicks(); + return end_ticks > start_ticks && end_ticks - start_ticks >= min_ticks; +} + +bool recordTaskBlockAtExit(ProfiledThread* current, ThreadFilter* thread_filter, + WallClockBlockTracker* tracker, jthread thread, + int start_depth, u64 block_token, u64 blocker, + u64 unblocking_span_id) { + u64 start_ticks = 0; + Context context{}; + if (!current->taskBlockExit(block_token, start_ticks, context)) { + return false; + } + + return finishTaskBlockAtExit( + current, thread_filter, tracker, thread, start_depth, block_token, + start_ticks, context, blocker, unblocking_span_id); +} + +bool finishTaskBlockAtExit(ProfiledThread* current, + ThreadFilter* thread_filter, + WallClockBlockTracker* tracker, jthread thread, + int start_depth, u64 block_token, u64 start_ticks, + const Context& context, u64 blocker, + u64 unblocking_span_id) { + Profiler* profiler = Profiler::instance(); + bool recording_enabled = profiler->taskBlockEnabled(); + TaskBlockActivity activity; + + ThreadFilter::SlotID slot_id = WallClockBlockTracker::tokenSlotId(block_token); + u64 generation = WallClockBlockTracker::tokenGeneration(block_token); + // beginTaskBlock0 resolves its slot through ThreadFilter::ensureCurrentThreadSlot(), + // which self-heals a cached-but-stale slot_id (e.g. after a recording restart + // reset the registry) back to this tid's real slot. The block duration between + // enter and exit can span such a reset, so re-validate here too instead of + // trusting the cached value directly - otherwise a stale cache makes the slot + // comparison below meaningless and silently drops the event uncounted. + ThreadFilter::SlotID current_slot = thread_filter->ensureCurrentThreadSlot(current); + BlockRunSnapshot snapshot; + bool exited = current_slot == slot_id && + tracker->snapshotAndExitBlockedRun(thread_filter, slot_id, generation, + &snapshot); + + if (!activity.active()) { + // TaskBlockActivity's constructor already incremented TASK_BLOCK_DROPPED_ROTATION. + return false; + } + if (!recording_enabled || !exited) { + return false; + } + if (!snapshot.context_eligible) { + Counters::increment(TASK_BLOCK_SKIPPED_CONTEXT_WINDOW); + return false; + } + + return recordTaskBlockIfEligible( + current->tid(), thread, start_depth, start_ticks, TSC::ticks(), context, + blocker, unblocking_span_id, snapshot.active_state, true); +} diff --git a/ddprof-lib/src/main/cpp/taskBlockRecorder.h b/ddprof-lib/src/main/cpp/taskBlockRecorder.h new file mode 100644 index 0000000000..a7126b4a46 --- /dev/null +++ b/ddprof-lib/src/main/cpp/taskBlockRecorder.h @@ -0,0 +1,98 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +#ifndef _TASK_BLOCK_RECORDER_H +#define _TASK_BLOCK_RECORDER_H + +#include "context.h" +#include "counters.h" +#include "event.h" +#include "profiler.h" +#include "tsc.h" + +void initializeTaskBlockDurationThreshold(); +bool exceedsMinTaskBlockDuration(u64 start_ticks, u64 end_ticks); + +bool recordTaskBlockAtExit(ProfiledThread* current, ThreadFilter* thread_filter, + WallClockBlockTracker* tracker, jthread thread, + int start_depth, u64 block_token, u64 blocker, + u64 unblocking_span_id); + +// Completes block-run lifecycle cleanup for an already-exited producer and +// records its event only when dump/stop rotation admits the recording work. +// Cleanup is deliberately performed even when admission is rejected so an +// application thread never waits for rotation and suppression cannot be left +// armed. +bool finishTaskBlockAtExit(ProfiledThread* current, + ThreadFilter* thread_filter, + WallClockBlockTracker* tracker, jthread thread, + int start_depth, u64 block_token, u64 start_ticks, + const Context& context, u64 blocker, + u64 unblocking_span_id); + +class TaskBlockActivity { + private: + Profiler* _profiler; + bool _active; + bool _owns_activity; + + public: + explicit TaskBlockActivity(bool already_active = false) + : _profiler(Profiler::instance()), + _active(already_active || _profiler->tryEnterTaskBlockActivity()), + _owns_activity(!already_active && _active) { + if (!_active) Counters::increment(TASK_BLOCK_DROPPED_ROTATION); + } + + ~TaskBlockActivity() { + if (_owns_activity) _profiler->leaveTaskBlockActivity(); + } + + bool active() const { return _active; } +}; + +static inline bool taskBlockPassesBasicEligibility(u64 start_ticks, u64 end_ticks, + const Context& ctx) { + if (ctx.spanId != 0) { + Counters::increment(TASK_BLOCK_SKIPPED_TRACE_CONTEXT); + return false; + } + if (!exceedsMinTaskBlockDuration(start_ticks, end_ticks)) { + Counters::increment(TASK_BLOCK_SKIPPED_TOO_SHORT); + return false; + } + return true; +} + +static inline bool recordTaskBlockIfEligible( + int tid, jthread thread, int start_depth, u64 start_ticks, u64 end_ticks, + const Context& ctx, u64 blocker, u64 unblocking_span_id, + OSThreadState observed_state, bool activity_already_held = false) { + TaskBlockActivity activity(activity_already_held); + if (!activity.active() || + !taskBlockPassesBasicEligibility(start_ticks, end_ticks, ctx)) { + return false; + } + TaskBlockEvent event{}; + event._start = start_ticks; + event._end = end_ticks; + event._blocker = blocker; + event._unblockingSpanId = unblocking_span_id; + event._ctx = ctx; + event._observedBlockingState = observed_state; + Profiler::TaskBlockRecordResult result = + Profiler::instance()->recordTaskBlock(tid, thread, start_depth, &event); + if (result == Profiler::TaskBlockRecordResult::RECORDED) { + Counters::increment(TASK_BLOCK_EMITTED); + return true; + } + Counters::increment( + result == Profiler::TaskBlockRecordResult::STACK_CAPTURE_FAILED + ? TASK_BLOCK_STACK_CAPTURE_FAILED + : TASK_BLOCK_RECORD_FAILED); + return false; +} + +#endif // _TASK_BLOCK_RECORDER_H diff --git a/ddprof-lib/src/main/cpp/threadFilter.cpp b/ddprof-lib/src/main/cpp/threadFilter.cpp index 598f4a2487..2fc69ac966 100644 --- a/ddprof-lib/src/main/cpp/threadFilter.cpp +++ b/ddprof-lib/src/main/cpp/threadFilter.cpp @@ -125,7 +125,7 @@ ThreadFilter::SlotID ThreadFilter::registerThread(int tid) { return -1; } // Callers retry registration on every hook call while they hold no slot - // (see ensureCurrentThreadFilterSlot() in javaApi.cpp), so once the + // (see ensureCurrentThreadSlot() below), so once the // registry is full, threads past capacity would otherwise serialize on // _registry_lock on every filterThreadAdd0/parkEnter0/blockEnter0 call. // Reject them lock-free instead. A tid that is already indexed must still @@ -166,7 +166,7 @@ ThreadFilter::SlotID ThreadFilter::registerThread(int tid) { slot->recording_epoch.store(0, std::memory_order_relaxed); slot->context_window_state.store(0, std::memory_order_relaxed); if (_block_tracker != nullptr) { - _block_tracker->resetSlot(reused_slot, OSThreadState::UNKNOWN); + _block_tracker->resetSlotForReuse(reused_slot); } if (!indexOrRollback(*slot, reused_slot, tid)) { pushToFreeList(reused_slot); @@ -211,7 +211,7 @@ ThreadFilter::SlotID ThreadFilter::registerThread(int tid) { slot->recording_epoch.store(0, std::memory_order_relaxed); slot->context_window_state.store(0, std::memory_order_relaxed); if (_block_tracker != nullptr) { - _block_tracker->resetSlot(index, OSThreadState::UNKNOWN); + _block_tracker->resetSlot(index); } if (!indexOrRollback(*slot, index, tid)) { pushToFreeList(index); @@ -234,7 +234,7 @@ void ThreadFilter::refreshSlotForRecording(SlotID slot_id, Slot* slot, Recording slot->recording_epoch.store(0, std::memory_order_release); // add()/remove() only ever act on the calling thread's own slot - // (ensureCurrentThreadFilterSlot uses current->tid()), and this method is + // (ensureCurrentThreadSlot uses current->tid()), and this method is // only reached via registerThread() re-registering the calling thread's // own tid, so no other thread can be transitioning this slot's context // window concurrently. The CAS (instead of a plain store) is defensive: @@ -249,7 +249,7 @@ void ThreadFilter::refreshSlotForRecording(SlotID slot_id, Slot* slot, Recording } if (_block_tracker != nullptr) { - _block_tracker->resetSlot(slot_id, OSThreadState::UNKNOWN); + _block_tracker->resetSlot(slot_id); } slot->recording_epoch.store(epoch, std::memory_order_release); } @@ -415,6 +415,49 @@ ThreadFilter::Slot* ThreadFilter::activeSlotForId(SlotID slot_id, return slot; } +ThreadFilter::SlotID ThreadFilter::ensureCurrentThreadSlot(ProfiledThread* current) { + int tid = current->tid(); + if (unlikely(tid < 0)) { + return -1; + } + + SlotID slot_id = current->filterSlotId(); + if (likely(slot_id >= 0)) { + if (likely(activeSlotForId(slot_id, tid) != nullptr)) { + return slot_id; + } + current->setFilterSlotId(-1); + } + + // Bounded to at most once per thread lifetime (cold TLS) plus once per + // recording-epoch transition this thread observes (stale cached slot), + // not a per-call cost. THREAD_REGISTRY_HOOK_REREGISTRATION counts every + // attempt, including lock-free rejections inside registerThread() when + // the registry is full (tracked separately by + // THREAD_REGISTRY_CAPACITY_EXHAUSTED). + Counters::increment(THREAD_REGISTRY_HOOK_REREGISTRATION); + slot_id = registerThread(tid); + if (slot_id >= 0) { + current->setFilterSlotId(slot_id); + } + return slot_id; +} + +bool ThreadFilter::lookupThreadEntry(ThreadEntry& entry, + RecordingEpoch epoch) const { + SlotID slot_id = -1; + Slot* slot = epoch != 0 ? lookupByTid(entry.tid, epoch, &slot_id) + : lookupByTid(entry.tid, &slot_id); + if (slot == nullptr) { + return false; + } + entry.slot = slot; + entry.slot_id = slot_id; + entry.lifecycle_generation = slot->lifecycleGeneration(); + entry.recording_epoch = slot->recordingEpoch(); + return true; +} + void ThreadFilter::initFreeList() { // Initialize the free list storage for (int i = 0; i < kFreeListSize; ++i) { @@ -468,14 +511,15 @@ bool ThreadFilter::add(int tid, SlotID slot_id) { // A block/park run's exit can be missed (e.g. an exception path with // no finally), leaving the slot "owned" forever and permanently // suppressed. add() is only ever called by the slot's own thread - // (ensureCurrentThreadFilterSlot() uses current->tid()), which - // cannot itself be inside a block run at this exact point, so it is - // always safe to drop a stuck active block run on every context - // entry. Only the active-run fields are cleared, not the - // unowned-blocked sampling weight -- see - // WallClockBlockTracker::BlockState::clearActiveBlockRun(). + // (ensureCurrentThreadSlot() uses current->tid()), which cannot + // itself be inside a JAVA/JVMTI/NATIVE block run at this exact point, + // so it is always safe to drop a stuck one on every context entry. + // Only the active-run fields are cleared, not the unowned-blocked + // sampling weight -- see + // WallClockBlockTracker::BlockState::clearActiveBlockRun(), which + // also explains why a TASK_BLOCK run is exempt from this clear. if (_block_tracker != nullptr) { - _block_tracker->clearActiveBlockRun(slot_id, OSThreadState::UNKNOWN); + _block_tracker->clearActiveBlockRun(slot_id); } slot.enterContextWindow(); return true; @@ -516,11 +560,19 @@ void ThreadFilter::unregisterThreadLocked(SlotID slot_id, int expected_tid) { int tid = slot->nativeTid(); if (expected_tid >= 0 && tid != expected_tid) return; unindexSlot(slot_id, tid); + if (_block_tracker != nullptr && _block_tracker->hasActiveBlockRun(slot_id)) { + // A thread should never unregister while still holding an active block + // run (its own synchronous begin/end pair must complete on the same + // still-live thread first). If this ever fires, block_generation resets + // on the next reuse of this slot are relying on an invariant that just + // broke -- investigate immediately rather than trusting the reset is safe. + Counters::increment(THREAD_REGISTRY_UNREGISTER_ACTIVE_BLOCK_RUN); + } slot->recording_epoch.store(0, std::memory_order_release); slot->tid.store(-1, std::memory_order_release); slot->context_window_state.store(0, std::memory_order_release); if (_block_tracker != nullptr) { - _block_tracker->resetSlot(slot_id, OSThreadState::UNKNOWN); + _block_tracker->resetSlot(slot_id); } pushToFreeList(slot_id); } @@ -677,8 +729,8 @@ void ThreadFilter::clearActive() { void ThreadFilter::resetSlotRunState(SlotID slot_id) { if (slot_id < 0 || _block_tracker == nullptr) return; // Clear stale suppression state so a new thread in this slot cannot inherit - // its predecessor's active block or once-per-run sampled marker. - _block_tracker->resetSlot(slot_id, OSThreadState::UNKNOWN); + // its predecessor's active block or sampled generation. + _block_tracker->resetSlot(slot_id); } void ThreadFilter::init(const char* filter, bool track_unfiltered_wall) { diff --git a/ddprof-lib/src/main/cpp/threadFilter.h b/ddprof-lib/src/main/cpp/threadFilter.h index 4c6c1dbaba..53b41fb9a8 100644 --- a/ddprof-lib/src/main/cpp/threadFilter.h +++ b/ddprof-lib/src/main/cpp/threadFilter.h @@ -28,6 +28,7 @@ struct ThreadEntry; // defined after ThreadFilter; carries a pointer to a ThreadFilter::Slot class WallClockBlockTracker; // wall-clock owned/unowned block-run suppression state, see wallClockBlockTracker.h +class ProfiledThread; class ThreadFilter { public: @@ -193,7 +194,23 @@ class ThreadFilter { Slot* lookupByTid(int tid, SlotID* out_slot_id = nullptr) const; Slot* lookupByTid(int tid, RecordingEpoch epoch, SlotID* out_slot_id = nullptr) const; Slot* activeSlotForId(SlotID slot_id, int tid) const; + // Populates lifecycle metadata from an existing mapping without registering + // the TID. Timer-side observation must remain read-only. + bool lookupThreadEntry(ThreadEntry& entry, RecordingEpoch epoch) const; void deactivateRecording(); + SlotID slotIdByTid(int tid) const { return lookupSlotIdByTid(tid); } + + // Validates `current`'s cached filter slot against this registry and + // self-heals it via registerThread() if it is missing or stale (e.g. an + // unfiltered recording restart changed the recording epoch since the + // slot was cached). registerThread() returns the same slot number for a tid + // that is already indexed, so healing never reassigns a live thread to a + // different slot. Every block-run JNI entry point that resolves its own + // slot (filterThreadAdd0, beginTaskBlock0, blockEnter0/parkEnter0) must + // go through this instead of reading ProfiledThread::filterSlotId() + // directly, since a stale cached value would otherwise make slot + // comparisons against a block-run token meaningless. + SlotID ensureCurrentThreadSlot(ProfiledThread* current); private: diff --git a/ddprof-lib/src/main/cpp/threadLocalData.h b/ddprof-lib/src/main/cpp/threadLocalData.h index 6e9a0c5dee..e29d415018 100644 --- a/ddprof-lib/src/main/cpp/threadLocalData.h +++ b/ddprof-lib/src/main/cpp/threadLocalData.h @@ -88,6 +88,9 @@ class ProfiledThread : public ThreadLocalData { u32 _recording_epoch; volatile u32 _misc_flags; u64 _park_block_token; + u64 _task_block_start_ticks; + u64 _task_block_token; + Context _task_block_context; int _filter_slot_id; // Slot ID for thread filtering uint8_t _init_window; // Countdown for JVM thread init race window (PROF-13072) volatile int _signal_depth; // Nested signal-handler depth (see SignalHandlerScope) @@ -110,7 +113,9 @@ class ProfiledThread : public ThreadLocalData { ProfiledThread(int tid) : ThreadLocalData(), _jmp_buf(nullptr), _pc(0), _sp(0), _span_id(0), _crash_depth(0), _tid(tid), _cpu_epoch(0), _wall_epoch(0), _call_trace_id(0), _recording_epoch(0), _misc_flags(0), - _park_block_token(0), _filter_slot_id(-1), _init_window(0), + _park_block_token(0), _task_block_start_ticks(0), + _task_block_token(0), _task_block_context{}, _filter_slot_id(-1), + _init_window(0), _signal_depth(0), _otel_ctx_initialized(false), _otel_ctx_record{}, _otel_tag_encodings{}, _otel_local_root_span_id(0) { @@ -418,6 +423,23 @@ class ProfiledThread : public ThreadLocalData { _park_block_token = token; } + inline bool taskBlockEnter(u64 token, u64 start_ticks, + const Context& context) { + if (token == 0 || _task_block_token != 0) return false; + _task_block_start_ticks = start_ticks; + _task_block_context = context; + _task_block_token = token; + return true; + } + + inline bool taskBlockExit(u64 token, u64& start_ticks, Context& context) { + if (token == 0 || _task_block_token != token) return false; + start_ticks = _task_block_start_ticks; + context = _task_block_context; + _task_block_token = 0; + return true; + } + // Returns false if the thread was not parked (idempotent). inline bool parkExit(u64 &park_block_token) { u32 prev = __atomic_fetch_and(&_misc_flags, ~FLAG_PARKED, __ATOMIC_ACQ_REL); diff --git a/ddprof-lib/src/main/cpp/threadState.h b/ddprof-lib/src/main/cpp/threadState.h index cfa46edec3..ca89d5c62f 100644 --- a/ddprof-lib/src/main/cpp/threadState.h +++ b/ddprof-lib/src/main/cpp/threadState.h @@ -32,7 +32,7 @@ enum class ExecutionMode : int { inline ExecutionMode getThreadExecutionMode(); inline OSThreadState getOSThreadState(); -// Shared by BaseWallClock's precheck path and WallClockBlockTracker::shouldSuppressOwnedBlock(): +// Shared by BaseWallClock's precheck path and WallClockBlockTracker::ownedBlockGeneration(): // both need the same set of blocked/waiting states eligible for once-per-run suppression. inline bool isPrecheckSuppressionState(OSThreadState state) { return state == OSThreadState::SLEEPING || diff --git a/ddprof-lib/src/main/cpp/wallClock.cpp b/ddprof-lib/src/main/cpp/wallClock.cpp index 9398d6f0b0..77c94e2fb5 100644 --- a/ddprof-lib/src/main/cpp/wallClock.cpp +++ b/ddprof-lib/src/main/cpp/wallClock.cpp @@ -55,8 +55,8 @@ static inline bool hasKnownActiveTraceContext(ProfiledThread* thread) { struct WallPrecheckResult { bool suppress = false; - WallClockBlockTracker::BlockState* slot_to_arm = nullptr; - OSThreadState state_to_arm = OSThreadState::UNKNOWN; + WallClockBlockTracker::BlockState* owned_block_slot = nullptr; + u64 owned_block_generation = 0; OSThreadState observed_state = OSThreadState::UNKNOWN; bool observed_state_valid = false; WallClockBlockTracker::BlockState* unowned_weight_slot = nullptr; @@ -67,19 +67,19 @@ struct WallPrecheckResult { OSThreadState flush_state = OSThreadState::UNKNOWN; }; -static inline void incrementSuppressedSampledRun() { - Counters::increment(WC_SIGNAL_SUPPRESSED_SAMPLED_RUN); - WallClockCounters::incrementSuppressedSampledRun(); +static inline void incrementSuppressedOwnedBlock() { + Counters::increment(WC_SIGNAL_SUPPRESSED_OWNED_BLOCK); + WallClockCounters::incrementSuppressedOwnedBlock(); } bool BaseWallClock::suppressAlreadySampled(const ThreadEntry& entry) { ThreadFilter* thread_filter = Profiler::instance()->threadFilter(); WallClockBlockTracker* tracker = Profiler::instance()->blockTracker(); - if (!tracker->shouldSuppressOwnedBlock(thread_filter, entry)) { - return false; + if (tracker->isOwnedBlockSuppressionCandidate(thread_filter, entry)) { + incrementSuppressedOwnedBlock(); + return true; } - incrementSuppressedSampledRun(); - return true; + return false; } static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, @@ -103,39 +103,31 @@ static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, return result; } - // In an unfiltered recording, context threads keep their normal MethodSample - // stream. Only owned blocks that remain outside the context window may replace - // repeated signals. - if (registry->unfilteredWallTrackingActive() && slot->inContextWindow()) { + // Owned blocks replace repeated signals only after their current generation + // has produced one MethodSample. Context-scoped profiling must continue + // sampling its selected threads normally. + if (!registry->unfilteredWallTrackingActive() || slot->inContextWindow()) { return result; } - OSThreadState active_block_state = block_slot->activeBlockState(); - BlockRunOwner active_block_owner = block_slot->activeBlockOwner(); - bool has_owned_block = - active_block_owner != BlockRunOwner::NONE && - isPrecheckSuppressionState(active_block_state) && - (!registry->unfilteredWallTrackingActive() || - block_slot->activeBlockRemainedOutsideContextWindow(slot)); - if (has_owned_block) { - if (block_slot->sampledThisRun() && - active_block_state == block_slot->lastSampledState()) { - incrementSuppressedSampledRun(); + ThreadEntry entry{current->tid(), slot, slot_id, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + u64 block_generation = 0; + bool already_sampled = false; + if (tracker->ownedBlockDecision(registry, entry, already_sampled, + block_generation)) { + if (already_sampled) { + incrementSuppressedOwnedBlock(); result.suppress = true; return result; } - // Arm only after the MethodSample has been successfully recorded. If the - // JFR write is skipped due to lock contention, the next signal must retry - // instead of losing the only stack for this blocked run. - result.slot_to_arm = block_slot; - result.state_to_arm = active_block_state; + // Arm only after recordSample succeeds. A skipped JFR write must leave the + // run eligible so the next signal retries instead of losing its only stack. + result.owned_block_slot = block_slot; + result.owned_block_generation = block_generation; return result; } - - // Unfiltered tracking exists only to support explicit context and owned-block - // hooks. Keep unowned observations on ordinary per-signal sampling: the JVMTI - // path has no call_trace_id with which to replay a suppressed tail. - if (registry->unfilteredWallTrackingActive()) { + if (!block_slot->unownedBlockedFallbackEnabled()) { return result; } @@ -159,6 +151,10 @@ static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, static inline void finishWallPrecheck(const WallPrecheckResult& precheck, bool recorded, u64 recorded_call_trace_id = 0) { + if (recorded && precheck.owned_block_slot != nullptr) { + precheck.owned_block_slot->markBlockGenerationSampled( + precheck.owned_block_generation); + } if (!recorded && precheck.unowned_weight_slot != nullptr) { precheck.unowned_weight_slot->restoreUnownedBlockedWeight( precheck.unowned_weight); @@ -169,9 +165,6 @@ static inline void finishWallPrecheck(const WallPrecheckResult& precheck, recorded_call_trace_id, precheck.observed_state); } } - if (recorded && precheck.slot_to_arm != nullptr) { - precheck.slot_to_arm->markSampledThisRun(precheck.state_to_arm); - } } static inline void recordDeferredWallSample(int tid, u64 call_trace_id, @@ -263,12 +256,10 @@ void WallClockASGCT::signalHandler(int signo, siginfo_t *siginfo, void *ucontext if (tickInitWindowIfNeeded(current)) { return; } - // Once-per-run filter (wallprecheck=true): for untraced threads, exact - // suppression is only valid while an explicit lifecycle hook owns the blocked - // interval. Raw OS thread state is only an observation; it cannot distinguish - // one long sleep from several short sleeps separated by runnable gaps between - // signals. Unowned blocked observations therefore use weighted fallback - // sampling instead of arming sampled_this_run. + // Once-per-run filter (wallprecheck=true): an explicitly owned block keeps + // its first successful MethodSample and suppresses subsequent signals. + // Unowned blocked observations use weighted fallback sampling because raw OS + // state cannot distinguish one long sleep from several shorter runs. WallPrecheckResult precheck = prepareWallPrecheck(current, _precheck); if (precheck.suppress) { return; @@ -382,15 +373,7 @@ WallClockCandidateOutcome BaseWallClock::sampleThreadCommon( ThreadFilter::RecordingEpoch recording_epoch) { if (lookup_registry_slot && entry.slot == nullptr) { registry_lookups++; - ThreadFilter::SlotID slot_id = -1; - ThreadFilter::Slot* slot = - thread_filter->lookupByTid(entry.tid, recording_epoch, &slot_id); - if (slot != nullptr) { - entry.slot = slot; - entry.slot_id = slot_id; - entry.lifecycle_generation = slot->lifecycleGeneration(); - entry.recording_epoch = slot->recordingEpoch(); - } + thread_filter->lookupThreadEntry(entry, recording_epoch); } // Missing entries, including capacity rejections, stay eligible for ordinary // sampling. Registry admission is only a precheck optimization in unfiltered mode. diff --git a/ddprof-lib/src/main/cpp/wallClock.h b/ddprof-lib/src/main/cpp/wallClock.h index aaa72b150a..c63804ba97 100644 --- a/ddprof-lib/src/main/cpp/wallClock.h +++ b/ddprof-lib/src/main/cpp/wallClock.h @@ -173,7 +173,7 @@ class BaseWallClock : public Engine { epoch.updateNumSamplableThreads(num_samplable_threads); epoch.updateNumFailedSamples(num_failures); epoch.updateNumSuccessfulSamples(num_successful_samples); - epoch.addNumSuppressedSampledRun(WallClockCounters::drainSuppressedSampledRun()); + epoch.addNumSuppressedOwnedBlock(WallClockCounters::drainSuppressedOwnedBlock()); epoch.updateNumExitedThreads(threads_already_exited); epoch.updateNumPermissionDenied(permission_denied); u64 endTime = TSC::ticks(); diff --git a/ddprof-lib/src/main/cpp/wallClockBlockTracker.cpp b/ddprof-lib/src/main/cpp/wallClockBlockTracker.cpp index 80c5ff4eb4..15475bd7ec 100644 --- a/ddprof-lib/src/main/cpp/wallClockBlockTracker.cpp +++ b/ddprof-lib/src/main/cpp/wallClockBlockTracker.cpp @@ -31,59 +31,123 @@ u64 WallClockBlockTracker::enterBlockedRun(ThreadFilter* registry, ThreadFilter: _block_admission_hook(_block_admission_hook_arg); } #endif + if (state == OSThreadState::UNKNOWN) return 0; ThreadFilter::Slot* identity_slot = registry->slotForId(slot_id); BlockState* block_slot = slotForId(slot_id); if (identity_slot == nullptr || block_slot == nullptr) { return 0; } - u32 generation = 0; - if (!block_slot->trySetActiveBlockRun(identity_slot, state, owner, &generation, - registry->unfilteredWallTrackingActive())) { + u64 generation = 0; + if (!block_slot->tryPrepareActiveBlockRun(identity_slot, owner, &generation, + registry->unfilteredWallTrackingActive())) { return 0; } - return WallClockBlockTracker::encodeBlockRunToken(slot_id, generation); + block_slot->publishActiveBlockRun(state); + return encodeBlockRunToken(slot_id, generation); } void WallClockBlockTracker::exitBlockedRun(ThreadFilter::SlotID slot_id) { BlockState* s = slotForId(slot_id); if (s != nullptr) { - s->resetSlot(OSThreadState::RUNNABLE); + s->resetSlot(); } } -bool WallClockBlockTracker::exitBlockedRun(ThreadFilter::SlotID slot_id, u32 generation) { +static inline bool isActiveRun(const WallClockBlockTracker::BlockState* s, u64 generation) { + return s != nullptr && generation != 0 && + s->activeBlockState() != OSThreadState::UNKNOWN && + s->activeBlockOwner() != BlockRunOwner::NONE && + s->blockGeneration() == generation; +} + +bool WallClockBlockTracker::exitBlockedRun(ThreadFilter::SlotID slot_id, u64 generation) { + BlockState* s = slotForId(slot_id); + if (!isActiveRun(s, generation)) { + return false; + } + s->resetSlot(); + return true; +} + +bool WallClockBlockTracker::snapshotAndExitBlockedRun(ThreadFilter* registry, + ThreadFilter::SlotID slot_id, + u64 generation, + BlockRunSnapshot* snapshot) { + ThreadFilter::Slot* identity_slot = registry->slotForId(slot_id); BlockState* s = slotForId(slot_id); - if (s == nullptr || generation == 0 || s->blockGeneration() != generation) { + if (identity_slot == nullptr || !isActiveRun(s, generation)) { return false; } - s->resetSlot(OSThreadState::RUNNABLE); + if (snapshot != nullptr) *snapshot = s->snapshotBlockRun(identity_slot); + s->resetSlot(); return true; } -void WallClockBlockTracker::resetSlot(ThreadFilter::SlotID slot_id, OSThreadState state) { +void WallClockBlockTracker::resetSlot(ThreadFilter::SlotID slot_id) { BlockState* s = slotForId(slot_id); if (s != nullptr) { - s->resetSlot(state); + s->resetSlot(); + } +} + +void WallClockBlockTracker::resetSlotForReuse(ThreadFilter::SlotID slot_id) { + BlockState* s = slotForId(slot_id); + if (s != nullptr) { + s->resetBlockGeneration(); + s->resetSlot(); } } void WallClockBlockTracker::resetAll() { for (ThreadFilter::SlotID slot_id = 0; slot_id < ThreadFilter::kMaxThreads; ++slot_id) { - _slots[slot_id].resetSlot(OSThreadState::UNKNOWN); + _slots[slot_id].resetSlot(); } } -void WallClockBlockTracker::clearActiveBlockRun(ThreadFilter::SlotID slot_id, OSThreadState state) { +void WallClockBlockTracker::clearActiveBlockRun(ThreadFilter::SlotID slot_id) { BlockState* s = slotForId(slot_id); if (s != nullptr) { - s->clearActiveBlockRun(state); + s->clearActiveBlockRun(); } } -bool WallClockBlockTracker::shouldSuppressOwnedBlock(ThreadFilter* registry, - const ThreadEntry& entry) const { +bool WallClockBlockTracker::hasActiveBlockRun(ThreadFilter::SlotID slot_id) const { + const BlockState* s = slotForId(slot_id); + return s != nullptr && s->activeBlockOwner() != BlockRunOwner::NONE; +} + +void WallClockBlockTracker::collectUnownedBlockedTraceIds( + const std::function& visit) const { + for (const BlockState& slot : _slots) { + u64 call_trace_id = slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire); + if (call_trace_id != 0) { + visit(call_trace_id); + } + } +} + +bool WallClockBlockTracker::activeOwnedBlockGeneration(ThreadFilter* registry, + const ThreadEntry& entry, + u64& generation) const { + bool already_sampled = false; + return ownedBlockGeneration(registry, entry, generation, already_sampled); +} + +bool WallClockBlockTracker::isOwnedBlockSuppressionCandidate(ThreadFilter* registry, + const ThreadEntry& entry) const { + u64 generation = 0; + bool already_sampled = false; + return ownedBlockGeneration(registry, entry, generation, already_sampled) && + already_sampled; +} + +bool WallClockBlockTracker::ownedBlockGeneration(ThreadFilter* registry, + const ThreadEntry& entry, + u64& generation, + bool& already_sampled) const { ThreadFilter::Slot* identity_slot = entry.slot; - if (identity_slot == nullptr || identity_slot->nativeTid() != entry.tid || + if (!registry->unfilteredWallTrackingActive() || identity_slot == nullptr || + identity_slot->nativeTid() != entry.tid || identity_slot->lifecycleGeneration() != entry.lifecycle_generation) { return false; } @@ -92,36 +156,30 @@ bool WallClockBlockTracker::shouldSuppressOwnedBlock(ThreadFilter* registry, return false; } - const bool unfiltered_tracking = registry->unfilteredWallTrackingActive(); - ThreadFilter::RecordingEpoch epoch = 0; - if (unfiltered_tracking) { - epoch = registry->recordingEpoch(); - if (epoch == 0 || entry.recording_epoch != epoch || - identity_slot->recordingEpoch() != epoch) { - return false; - } + // active_block_state publishes the rest of the block-run payload. Acquire + // it before reading the context epoch, owner, or generation so those reads + // observe the stores that preceded publishActiveBlockRun(). + OSThreadState state = slot->activeBlockState(); + if (!isPrecheckSuppressionState(state)) return false; + + ThreadFilter::RecordingEpoch epoch = registry->recordingEpoch(); + if (epoch == 0 || entry.recording_epoch != epoch || + identity_slot->recordingEpoch() != epoch || + !slot->activeBlockRemainedOutsideContextWindow(identity_slot)) { + return false; } + u64 block_generation = slot->blockGeneration(); + BlockRunOwner owner = slot->activeBlockOwner(); + u64 sampled_generation = slot->sampledBlockGeneration(); + if (owner == BlockRunOwner::NONE) return false; + #ifdef UNIT_TEST if (_suppression_snapshot_hook != nullptr) { _suppression_snapshot_hook(_suppression_snapshot_hook_arg); } #endif - u32 block_generation = slot->blockGeneration(); - BlockRunOwner owner = slot->activeBlockOwner(); - OSThreadState state = slot->activeBlockState(); - bool context_eligible = - !unfiltered_tracking || slot->activeBlockRemainedOutsideContextWindow(identity_slot); - bool sampled = slot->sampledThisRun(); - OSThreadState last_sampled_state = - sampled ? slot->lastSampledState() : OSThreadState::UNKNOWN; - bool suppressible_state = isPrecheckSuppressionState(state); - if (owner == BlockRunOwner::NONE || !context_eligible || - !suppressible_state || !sampled || state != last_sampled_state) { - return false; - } - // The payload is spread across independent atomics. Accept it only if the // slot still represents the lifecycle and block run captured earlier in // this wall-clock timer-thread pass, when `entry` was populated — either @@ -131,14 +189,17 @@ bool WallClockBlockTracker::shouldSuppressOwnedBlock(ThreadFilter* registry, // template defined in wallClock.h). if (slot->activeBlockOwner() != owner || slot->blockGeneration() != block_generation || + slot->activeBlockState() != state || identity_slot->nativeTid() != entry.tid || - identity_slot->lifecycleGeneration() != entry.lifecycle_generation) { + identity_slot->lifecycleGeneration() != entry.lifecycle_generation || + slot->sampledBlockGeneration() != sampled_generation) { return false; } - if (unfiltered_tracking && - (registry->recordingEpoch() != epoch || identity_slot->recordingEpoch() != epoch || - !slot->activeBlockRemainedOutsideContextWindow(identity_slot))) { + if (registry->recordingEpoch() != epoch || identity_slot->recordingEpoch() != epoch || + !slot->activeBlockRemainedOutsideContextWindow(identity_slot)) { return false; } + generation = block_generation; + already_sampled = sampled_generation == block_generation; return true; } diff --git a/ddprof-lib/src/main/cpp/wallClockBlockTracker.h b/ddprof-lib/src/main/cpp/wallClockBlockTracker.h index 22801f03e9..47a1ff1488 100644 --- a/ddprof-lib/src/main/cpp/wallClockBlockTracker.h +++ b/ddprof-lib/src/main/cpp/wallClockBlockTracker.h @@ -19,8 +19,10 @@ #include #include #include +#include #include "arch.h" +#include "counters.h" #include "threadFilter.h" #include "threadState.h" @@ -29,6 +31,12 @@ enum class BlockRunOwner : int { JAVA = 1, JVMTI = 2, NATIVE = 3, + // Explicit, caller-paced runs opened by beginTaskBlock0/endTaskBlock0. + // Unlike JAVA/JVMTI/NATIVE (instrumentation hooks that assume their owning + // thread can never be inside a run when it calls ThreadFilter::add()), a + // TASK_BLOCK run can legitimately span an add()+remove() pair on its own + // thread - see BlockState::clearActiveBlockRun(). + TASK_BLOCK = 4, }; // Wall-clock owned/unowned block-run suppression state, addressed in parallel @@ -39,6 +47,11 @@ enum class BlockRunOwner : int { // (context-window state, unfiltered-tracking mode) take a ThreadFilter // pointer/Slot pointer as an explicit parameter rather than storing one, so // tests can pair a tracker with any ThreadFilter instance. +struct BlockRunSnapshot { + OSThreadState active_state{OSThreadState::UNKNOWN}; + bool context_eligible{false}; +}; + class WallClockBlockTracker { public: // Reports/retracts the ~128 KiB eager _slots allocation to NativeMem @@ -50,6 +63,12 @@ class WallClockBlockTracker { WallClockBlockTracker(); ~WallClockBlockTracker(); + static constexpr int kBlockRunSlotBits = 11; + static constexpr u64 kBlockRunSlotMask = (1ULL << kBlockRunSlotBits) - 1; + static constexpr u64 kMaxBlockRunGeneration = UINT64_MAX >> kBlockRunSlotBits; + static_assert(ThreadFilter::kMaxThreads == (1 << kBlockRunSlotBits), + "block-run token slot bits must cover every ThreadFilter slot"); + // One cache line per slot, mirroring ThreadFilter::Slot's own // false-sharing avoidance. BlockState instances are process-lifetime // (owned by WallClockBlockTracker's inline array), so a captured @@ -61,46 +80,20 @@ class WallClockBlockTracker { std::atomic unowned_blocked_decision_count{0}; std::atomic unowned_blocked_call_trace_id{0}; std::atomic active_block_context_epoch{0}; + std::atomic block_generation{0}; + // The most recent owned-block generation for which a MethodSample was + // recorded successfully. Generations are monotonic, so a delayed + // completion from an older run cannot mark a newer run as sampled. + std::atomic sampled_block_generation{0}; std::atomic unowned_blocked_state{OSThreadState::UNKNOWN}; std::atomic active_block_owner{static_cast(BlockRunOwner::NONE)}; - std::atomic block_generation{0}; - // Wall-clock once-per-run suppression state. The signal handler records the - // last sampled blocked state; the signal handler and timer thread read it to - // suppress duplicate samples, while lifecycle/block-exit paths reset it. - // Release/acquire on sampled_this_run pairs with relaxed last_sampled_state, - // following the standard flag+payload pattern. - std::atomic last_sampled_state{OSThreadState::UNKNOWN}; + std::atomic unowned_blocked_fallback_enabled{1}; // Set by explicit block enter/exit hooks. It lets the timer skip sending a signal // only while instrumentation still owns a suppressible blocking interval. std::atomic active_block_state{OSThreadState::UNKNOWN}; - std::atomic sampled_this_run{false}; - char padding[DEFAULT_CACHE_LINE_SIZE - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic) - - sizeof(std::atomic)]; + // The fields above fill the cache line exactly, so there is no padding + // member; alignas() and the static_assert below keep it at one line. - inline bool sampledThisRun() const { - return sampled_this_run.load(std::memory_order_acquire); - } - inline OSThreadState lastSampledState() const { - return last_sampled_state.load(std::memory_order_relaxed); - } - inline void markSampledThisRun(OSThreadState state) { - last_sampled_state.store(state, std::memory_order_relaxed); - sampled_this_run.store(true, std::memory_order_release); - } - inline void resetSampledRun(OSThreadState state) { - resetUnownedBlockedSampling(); - last_sampled_state.store(state, std::memory_order_relaxed); - sampled_this_run.store(false, std::memory_order_release); - } inline OSThreadState activeBlockState() const { return active_block_state.load(std::memory_order_acquire); } @@ -110,9 +103,42 @@ class WallClockBlockTracker { inline BlockRunOwner activeBlockOwner() const { return static_cast(active_block_owner.load(std::memory_order_acquire)); } - inline u32 blockGeneration() const { + inline u64 blockGeneration() const { return block_generation.load(std::memory_order_acquire); } +#ifdef UNIT_TEST + inline void setBlockGenerationForTest(u64 value) { + block_generation.store(value, std::memory_order_relaxed); + } +#endif + inline void resetBlockGeneration() { + block_generation.store(0, std::memory_order_relaxed); + } + inline u64 sampledBlockGeneration() const { + return sampled_block_generation.load(std::memory_order_acquire); + } + inline void markBlockGenerationSampled(u64 generation) { + u64 sampled = sampled_block_generation.load(std::memory_order_relaxed); + while (sampled < generation && + !sampled_block_generation.compare_exchange_weak( + sampled, generation, std::memory_order_release, + std::memory_order_relaxed)) { + } + } + inline void resetSampledBlockGeneration() { + sampled_block_generation.store(0, std::memory_order_relaxed); + } + inline bool unownedBlockedFallbackEnabled() const { + return unowned_blocked_fallback_enabled.load(std::memory_order_acquire) != 0; + } + inline void enableUnownedBlockedFallback() { + resetUnownedBlockedSampling(); + unowned_blocked_fallback_enabled.store(1, std::memory_order_release); + } + inline void disableUnownedBlockedFallback() { + unowned_blocked_fallback_enabled.store(0, std::memory_order_release); + resetUnownedBlockedSampling(); + } inline void resetUnownedBlockedSampling() { unowned_blocked_pending_weight.store(0, std::memory_order_relaxed); unowned_blocked_decision_count.store(0, std::memory_order_relaxed); @@ -152,9 +178,12 @@ class WallClockBlockTracker { } // identity_slot supplies the context-window state, which lives on // ThreadFilter::Slot. See ThreadFilter::Slot::rawContextWindowState(). - inline bool trySetActiveBlockRun(ThreadFilter::Slot* identity_slot, OSThreadState state, - BlockRunOwner owner, u32* generation_out, - bool outside_context_required) { + // On success the run is owned but not yet visible to readers; the + // caller publishes it with publishActiveBlockRun(). + inline bool tryPrepareActiveBlockRun(ThreadFilter::Slot* identity_slot, + BlockRunOwner owner, + u64* generation_out, + bool outside_context_required) { u64 context_state = identity_slot->rawContextWindowState(); if (outside_context_required && (context_state & 1) != 0) { return false; @@ -171,35 +200,54 @@ class WallClockBlockTracker { std::memory_order_release); return false; } - u32 generation = block_generation.fetch_add(1, std::memory_order_acq_rel) + 1; + u64 generation = block_generation.load(std::memory_order_relaxed); + if (generation == kMaxBlockRunGeneration) { + active_block_owner.store(static_cast(BlockRunOwner::NONE), + std::memory_order_release); + Counters::increment(THREAD_REGISTRY_BLOCK_GENERATION_SATURATED); + return false; + } + generation++; + block_generation.store(generation, std::memory_order_relaxed); active_block_context_epoch.store(context_state >> 1, std::memory_order_relaxed); - resetUnownedBlockedSampling(); - last_sampled_state.store(OSThreadState::UNKNOWN, std::memory_order_relaxed); - sampled_this_run.store(false, std::memory_order_relaxed); - active_block_state.store(state, std::memory_order_release); + resetSampledBlockGeneration(); + disableUnownedBlockedFallback(); *generation_out = generation; return true; } - inline void resetSlot(OSThreadState state) { - active_block_state.store(OSThreadState::UNKNOWN, std::memory_order_release); - resetSampledRun(state); - active_block_owner.store(static_cast(BlockRunOwner::NONE), std::memory_order_release); + inline void publishActiveBlockRun(OSThreadState state) { + active_block_state.store(state, std::memory_order_release); } - // Clears only the owned block-run fields (owner, active state, the - // once-per-run sampled marker), leaving the unowned-blocked - // statistical sampling weight untouched -- unlike resetSlot(), which - // is for registry-lifecycle events (slot reuse, epoch reset) where - // the predecessor's weight must not leak into the new owner. This - // narrower reset is for a context-window re-entry on the slot's own - // thread: it only needs to drop a block run whose exit was missed - // (e.g. an exception path with no finally), not disturb the - // amortized weight tracking, which spans context-window - // entries/exits by design. - inline void clearActiveBlockRun(OSThreadState state) { + inline void resetSlot() { active_block_state.store(OSThreadState::UNKNOWN, std::memory_order_release); + resetSampledBlockGeneration(); + enableUnownedBlockedFallback(); active_block_owner.store(static_cast(BlockRunOwner::NONE), std::memory_order_release); - last_sampled_state.store(state, std::memory_order_relaxed); - sampled_this_run.store(false, std::memory_order_release); + } + // Drops an owned block run whose exit was missed (e.g. an exception + // path with no finally). A no-op when no run is owned, so the + // unowned-blocked sampling weight, which spans context-window + // entries/exits by design, is left untouched on every ordinary + // context entry. When a run is owned, tryPrepareActiveBlockRun() + // already disabled and cleared the unowned fallback, so resetSlot() + // loses no weight. block_generation is kept, so the stale token's + // eventual exit fails its generation check. + // + // TASK_BLOCK is exempt: beginTaskBlock0/endTaskBlock0 pair explicitly + // around caller-controlled code, so the same thread calling + // ThreadFilter::add() mid-run is an expected crossing, not a stuck + // leak. Tearing the run down here would make endTaskBlock0 see a + // "never started" run instead of a "crossed" one, losing the + // TASK_BLOCK_SKIPPED_CONTEXT_WINDOW signal. Leaving it alone is safe: + // enterContextWindow() already bumped the context epoch, so + // activeBlockRemainedOutsideContextWindow() reports it ineligible at + // exit without any extra bookkeeping here. + inline void clearActiveBlockRun() { + BlockRunOwner owner = activeBlockOwner(); + if (owner == BlockRunOwner::NONE || owner == BlockRunOwner::TASK_BLOCK) { + return; + } + resetSlot(); } // identity_slot supplies the context-window state, which lives on // ThreadFilter::Slot. See ThreadFilter::Slot::rawContextWindowState(). @@ -209,13 +257,17 @@ class WallClockBlockTracker { active_block_context_epoch.load(std::memory_order_acquire) == (context_state >> 1); } + inline BlockRunSnapshot snapshotBlockRun(ThreadFilter::Slot* identity_slot) const { + BlockRunSnapshot snapshot; + snapshot.active_state = activeBlockState(); + snapshot.context_eligible = activeBlockRemainedOutsideContextWindow(identity_slot); + return snapshot; + } }; static_assert(sizeof(BlockState) == DEFAULT_CACHE_LINE_SIZE, "BlockState must fit exactly one cache line"); static_assert(std::atomic::is_always_lock_free, "BlockState OSThreadState fields must be lock-free for signal-handler safety"); - static_assert(std::atomic::is_always_lock_free, - "BlockState::sampled_this_run must be lock-free for signal-handler safety"); static_assert(std::atomic::is_always_lock_free, "BlockState u64 fields must be lock-free for signal-handler safety"); @@ -228,15 +280,23 @@ class WallClockBlockTracker { } // Block-run tokens returned by enterBlockedRun() pack the generation in the - // upper 32 bits and slot_id + 1 in the lower 32 bits, so 0 means "no run". - static inline u64 encodeBlockRunToken(ThreadFilter::SlotID slot_id, u32 generation) { - return (static_cast(generation) << 32) | static_cast(slot_id + 1); + // upper 64 - kBlockRunSlotBits bits and slot_id in the low kBlockRunSlotBits + // bits. Generations start at 1, so 0 means "no run". + static inline u64 encodeBlockRunToken(ThreadFilter::SlotID slot_id, u64 generation) { + return (generation << kBlockRunSlotBits) | static_cast(slot_id); } static inline ThreadFilter::SlotID tokenSlotId(u64 token) { - return static_cast(static_cast(token) - 1); + return static_cast(token & kBlockRunSlotMask); } - static inline u32 tokenGeneration(u64 token) { - return static_cast(token >> 32); + static inline u64 tokenGeneration(u64 token) { + return token >> kBlockRunSlotBits; + } + static inline bool decodeBlockRunToken(u64 token, ThreadFilter::SlotID& slot_id, + u64& generation) { + if (token == 0) return false; + slot_id = tokenSlotId(token); + generation = tokenGeneration(token); + return generation != 0; } u64 enterBlockedRun(ThreadFilter* registry, ThreadFilter::SlotID slot_id, @@ -245,21 +305,51 @@ class WallClockBlockTracker { // reset/unregister paths use resetSlot()). Normal block lifecycles must // use the generation-checked overload so they cannot clear another owner. void exitBlockedRun(ThreadFilter::SlotID slot_id); - bool exitBlockedRun(ThreadFilter::SlotID slot_id, u32 generation); + bool exitBlockedRun(ThreadFilter::SlotID slot_id, u64 generation); + // Same generation check as exitBlockedRun(slot_id, generation), but + // captures the run's state and context eligibility before clearing it. + bool snapshotAndExitBlockedRun(ThreadFilter* registry, ThreadFilter::SlotID slot_id, + u64 generation, BlockRunSnapshot* snapshot); // Clears stale suppression state so a new/reused slot cannot inherit a - // predecessor's active block or once-per-run sampled marker. Called by - // ThreadFilter at its own registry-lifecycle decision points. - void resetSlot(ThreadFilter::SlotID slot_id, OSThreadState state); + // predecessor's active block or sampled generation. Called by ThreadFilter + // at its own registry-lifecycle decision points. block_generation is left + // untouched so tokens issued before the reset cannot match a later run. + void resetSlot(ThreadFilter::SlotID slot_id); + // Also restarts block_generation at 0. Only for a slot popped from the + // free list, whose previous owner unregistered after ending its runs (see + // THREAD_REGISTRY_UNREGISTER_ACTIVE_BLOCK_RUN). + void resetSlotForReuse(ThreadFilter::SlotID slot_id); void resetAll(); // Drops a stuck owned block run (one whose exit was missed) without // touching the unowned-blocked sampling weight. Called by // ThreadFilter::add() on every context-window entry; see // BlockState::clearActiveBlockRun() for why this is safe and why it // leaves the weight alone. - void clearActiveBlockRun(ThreadFilter::SlotID slot_id, OSThreadState state); - // Reads the complete timer-side suppression payload and rejects it if slot - // identity or block lifecycle changes before final validation. - bool shouldSuppressOwnedBlock(ThreadFilter* registry, const ThreadEntry& entry) const; + void clearActiveBlockRun(ThreadFilter::SlotID slot_id); + bool hasActiveBlockRun(ThreadFilter::SlotID slot_id) const; + // Liveness hook for CallTraceStorage::processTraces: a slot may cache a + // call_trace_id for a still-blocked thread's weighted fallback tail + // (recordUnownedBlockedSample) well before flushUnownedBlockedTail() emits + // it. Without this, a chunk rotation racing that window drops the trace, + // and the eventual deferred sample references an id with no constant-pool + // entry in the chunk it lands in. + void collectUnownedBlockedTraceIds(const std::function& visit) const; + + // Timer- and signal-side owned-block decisions. All of them read the + // complete suppression payload and reject it if slot identity or block + // lifecycle changes before final validation. + bool activeOwnedBlockGeneration(ThreadFilter* registry, const ThreadEntry& entry, + u64& generation) const; + bool isOwnedBlockSuppressionCandidate(ThreadFilter* registry, + const ThreadEntry& entry) const; + // Single-pass merge of activeOwnedBlockGeneration()/isOwnedBlockSuppressionCandidate(): + // callers that need both the generation and the already-sampled state should use this + // instead of calling the two wrappers above in sequence, which would re-validate the + // same slot atomics twice. + bool ownedBlockDecision(ThreadFilter* registry, const ThreadEntry& entry, + bool& already_sampled, u64& generation) const { + return ownedBlockGeneration(registry, entry, generation, already_sampled); + } #ifdef UNIT_TEST // Pauses a JNI park/block hook after its caller resolved the registry slot, @@ -278,6 +368,9 @@ class WallClockBlockTracker { #endif private: + bool ownedBlockGeneration(ThreadFilter* registry, const ThreadEntry& entry, + u64& generation, bool& already_sampled) const; + std::array _slots; #ifdef UNIT_TEST diff --git a/ddprof-lib/src/main/cpp/wallClockCounters.h b/ddprof-lib/src/main/cpp/wallClockCounters.h index f295ce87a8..72435b1046 100644 --- a/ddprof-lib/src/main/cpp/wallClockCounters.h +++ b/ddprof-lib/src/main/cpp/wallClockCounters.h @@ -17,19 +17,19 @@ static_assert(std::atomic::is_always_lock_free, // increment is counted in either the current drain or a later one. class WallClockCounters { private: - inline static std::atomic _suppressed_sampled_run{0}; + inline static std::atomic _suppressed_owned_block{0}; public: - static void incrementSuppressedSampledRun() { - _suppressed_sampled_run.fetch_add(1, std::memory_order_relaxed); + static void incrementSuppressedOwnedBlock() { + _suppressed_owned_block.fetch_add(1, std::memory_order_relaxed); } - static u64 drainSuppressedSampledRun() { - return (u64)_suppressed_sampled_run.exchange(0, std::memory_order_acq_rel); + static u64 drainSuppressedOwnedBlock() { + return (u64)_suppressed_owned_block.exchange(0, std::memory_order_acq_rel); } static void reset() { - _suppressed_sampled_run.store(0, std::memory_order_relaxed); + _suppressed_owned_block.store(0, std::memory_order_relaxed); } }; diff --git a/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfiler.java b/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfiler.java index aae738a477..7706b82ea2 100644 --- a/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfiler.java +++ b/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfiler.java @@ -394,16 +394,18 @@ public void recordQueueTime(long startTicks, } /** - * Internal hook called before {@code LockSupport.park}. This remains package-scoped - * until PR2 wires production TaskBlock instrumentation. + * Internal hook called before {@code LockSupport.park}. Park-specific TaskBlock + * production is intentionally separate from the public paired API. + * + * @return {@code true} when this call owns a park interval that must be closed */ - void parkEnter() { - parkEnter0(); + boolean parkEnter() { + return parkEnter0(); } /** * Internal hook called after {@code LockSupport.park}. Clears the parked flag. - * {@code blocker} and {@code unblockingSpanId} are reserved for PR2 TaskBlock use. + * {@code blocker} and {@code unblockingSpanId} are reserved for park instrumentation. */ void parkExit(long blocker, long unblockingSpanId) { parkExit0(blocker, unblockingSpanId); @@ -411,7 +413,7 @@ void parkExit(long blocker, long unblockingSpanId) { /** * Internal hook marking the current platform thread as entering an explicitly instrumented - * blocked interval. This is not public API in this PR; production TaskBlock wiring lands in PR2. + * blocked interval. The public paired API is {@link #beginTaskBlock()}. * * @param state native {@code OSThreadState} value for the blocked interval; * currently only {@code SLEEPING} is armed @@ -428,6 +430,50 @@ void blockExit(long token) { blockExit0(token); } + /** + * Begins an explicitly instrumented {@link Thread#sleep(long) sleeping} interval on the current + * platform thread. The resulting {@code TaskBlock} event is classified as {@code SLEEPING}. + * The returned token is bound to the current thread and must be passed to {@link + * #endTaskBlock(long, long, long)}. + * + * @return an opaque token, or {@code 0} when the interval could not be armed or the current + * thread is virtual; any non-zero value, including a negative value, is valid + */ + public long beginTaskBlock() { + return beginTaskBlock0(Thread.currentThread()); + } + + /** + * Ends a blocking interval created by {@link #beginTaskBlock()} and records its + * {@code TaskBlock} event when it satisfies the profiler's eligibility rules. + * Lifecycle state is cleared even when no event is recorded. + * + * @param token opaque token returned by {@link #beginTaskBlock()}; {@code 0} is the only + * invalid sentinel + * @param blocker stable identifier describing the blocking resource + * @param unblockingSpanId span responsible for unblocking the interval, or {@code 0} + * @return {@code true} when an event was recorded; virtual threads always return {@code false} + */ + public boolean endTaskBlock(long token, long blocker, long unblockingSpanId) { + return endTaskBlock0(Thread.currentThread(), token, blocker, unblockingSpanId); + } + + /** + * Test-only hook exercising {@link #beginTaskBlock0} with an explicit {@code thread}, to cover + * the rejection path when it does not identify the calling thread. + */ + long beginTaskBlockForThread(Thread thread) { + return beginTaskBlock0(thread); + } + + /** + * Test-only hook exercising {@link #endTaskBlock0} with an explicit {@code thread}, to cover + * the rejection path when it does not identify the calling thread. + */ + boolean endTaskBlockForThread(Thread thread, long token, long blocker, long unblockingSpanId) { + return endTaskBlock0(thread, token, blocker, unblockingSpanId); + } + /** * Get the ticks for the current thread. * @return ticks @@ -486,7 +532,7 @@ static int getTid() { private static native void recordQueueEnd0(long startTicks, long endTicks, String task, String scheduler, Thread origin, String queueType, int queueLength); - private static native void parkEnter0(); + private static native boolean parkEnter0(); private static native void parkExit0(long blocker, long unblockingSpanId); @@ -494,6 +540,11 @@ static int getTid() { private static native void blockExit0(long token); + private static native long beginTaskBlock0(Thread thread); + + private static native boolean endTaskBlock0(Thread thread, long token, long blocker, + long unblockingSpanId); + private static native long currentTicks0(); private static native long tscFrequency0(); diff --git a/ddprof-lib/src/test/cpp/jvmSupport_ut.cpp b/ddprof-lib/src/test/cpp/jvmSupport_ut.cpp index 83ab2ecb4f..ceb5b728aa 100644 --- a/ddprof-lib/src/test/cpp/jvmSupport_ut.cpp +++ b/ddprof-lib/src/test/cpp/jvmSupport_ut.cpp @@ -67,6 +67,192 @@ class JVMSupportTestAccessor { static constexpr LoadState FullyLoaded() { return JVMSupport::Fully_loaded; } }; +class JvmSupportThreadClassificationTest : public ::testing::Test { +protected: + using JniFunction = void (JNICALL*)(); + + static constexpr int GET_VERSION_INDEX = 4; + static constexpr int IS_VIRTUAL_THREAD_INDEX = 234; + static constexpr int FUNCTION_TABLE_SIZE = IS_VIRTUAL_THREAD_INDEX + 1; + + inline static jint jni_version; + inline static jboolean virtual_thread; + inline static int is_virtual_thread_calls; + inline static jobject last_thread; + + JniFunction function_table[FUNCTION_TABLE_SIZE]{}; + JNIEnv jni{}; + _jobject thread_object; + jthread thread = &thread_object; + bool _orig_hotspot = false; + + static jint JNICALL getVersion(JNIEnv*) { return jni_version; } + + static jboolean JNICALL isVirtualThread(JNIEnv*, jobject candidate) { + is_virtual_thread_calls++; + last_thread = candidate; + return virtual_thread; + } + + void SetUp() override { + _orig_hotspot = VMTestAccessor::getHotspot(); + VMTestAccessor::setHotspot(true); + jni_version = 0x00150000; + virtual_thread = JNI_FALSE; + is_virtual_thread_calls = 0; + last_thread = nullptr; + function_table[GET_VERSION_INDEX] = + reinterpret_cast(&getVersion); + function_table[IS_VIRTUAL_THREAD_INDEX] = + reinterpret_cast(&isVirtualThread); + jni.functions = + reinterpret_cast(function_table); + } + + void TearDown() override { + VMTestAccessor::setHotspot(_orig_hotspot); + } +}; + +TEST_F(JvmSupportThreadClassificationTest, NullInputsFailClosed) { + EXPECT_FALSE(JVMSupport::isPlatformThread(nullptr, thread)); + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, nullptr)); +} + +TEST_F(JvmSupportThreadClassificationTest, InvalidJniVersionFailsClosed) { + jni_version = 0; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + +TEST_F(JvmSupportThreadClassificationTest, PreJni19ThreadIsPlatform) { + jni_version = 0x000a0000; + function_table[IS_VIRTUAL_THREAD_INDEX] = nullptr; + EXPECT_TRUE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + +TEST_F(JvmSupportThreadClassificationTest, Jni19PlatformThreadIsAccepted) { + jni_version = 0x00130000; + EXPECT_TRUE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(1, is_virtual_thread_calls); + EXPECT_EQ(thread, last_thread); +} + +TEST_F(JvmSupportThreadClassificationTest, Jni19VirtualThreadIsRejected) { + jni_version = 0x00130000; + virtual_thread = JNI_TRUE; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(1, is_virtual_thread_calls); + EXPECT_EQ(thread, last_thread); +} + +TEST_F(JvmSupportThreadClassificationTest, MissingJni19FunctionFailsClosed) { + jni_version = 0x00130000; + function_table[IS_VIRTUAL_THREAD_INDEX] = nullptr; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + +TEST_F(JvmSupportThreadClassificationTest, Jni20PlatformThreadIsAccepted) { + jni_version = 0x00140000; + EXPECT_TRUE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(1, is_virtual_thread_calls); + EXPECT_EQ(thread, last_thread); +} + +TEST_F(JvmSupportThreadClassificationTest, Jni20VirtualThreadIsRejected) { + jni_version = 0x00140000; + virtual_thread = JNI_TRUE; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(1, is_virtual_thread_calls); + EXPECT_EQ(thread, last_thread); +} + +TEST_F(JvmSupportThreadClassificationTest, MissingJni20FunctionFailsClosed) { + jni_version = 0x00140000; + function_table[IS_VIRTUAL_THREAD_INDEX] = nullptr; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + +TEST_F(JvmSupportThreadClassificationTest, Jni21PlatformThreadIsAccepted) { + EXPECT_TRUE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(1, is_virtual_thread_calls); + EXPECT_EQ(thread, last_thread); +} + +TEST_F(JvmSupportThreadClassificationTest, Jni21VirtualThreadIsRejected) { + virtual_thread = JNI_TRUE; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(1, is_virtual_thread_calls); + EXPECT_EQ(thread, last_thread); +} + +TEST_F(JvmSupportThreadClassificationTest, MissingJni21FunctionFailsClosed) { + function_table[IS_VIRTUAL_THREAD_INDEX] = nullptr; + EXPECT_FALSE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + +// --------------------------------------------------------------------------- +// JvmSupportNonHotspotTest — verifies isPlatformThread() short-circuits to +// true on non-HotSpot JVMs at JNI>=19 without ever indexing the HotSpot-only +// IsVirtualThread vtable slot (which may not even be a valid function +// pointer there). +// --------------------------------------------------------------------------- +class JvmSupportNonHotspotTest : public ::testing::Test { +protected: + using JniFunction = void (JNICALL*)(); + + static constexpr int GET_VERSION_INDEX = 4; + static constexpr int IS_VIRTUAL_THREAD_INDEX = 234; + static constexpr int FUNCTION_TABLE_SIZE = IS_VIRTUAL_THREAD_INDEX + 1; + + inline static jint jni_version; + inline static int is_virtual_thread_calls; + + JniFunction function_table[FUNCTION_TABLE_SIZE]{}; + JNIEnv jni{}; + _jobject thread_object; + jthread thread = &thread_object; + bool _orig_hotspot = false; + + static jint JNICALL getVersion(JNIEnv*) { return jni_version; } + static jboolean JNICALL isVirtualThread(JNIEnv*, jobject) { + is_virtual_thread_calls++; + return JNI_TRUE; + } + + void SetUp() override { + _orig_hotspot = VMTestAccessor::getHotspot(); + VMTestAccessor::setHotspot(false); + jni_version = 0x00150000; + is_virtual_thread_calls = 0; + function_table[GET_VERSION_INDEX] = + reinterpret_cast(&getVersion); + function_table[IS_VIRTUAL_THREAD_INDEX] = + reinterpret_cast(&isVirtualThread); + jni.functions = + reinterpret_cast(function_table); + } + + void TearDown() override { + VMTestAccessor::setHotspot(_orig_hotspot); + } +}; + +TEST_F(JvmSupportNonHotspotTest, Jni21ThreadIsAcceptedWithoutIndexingVtable) { + EXPECT_TRUE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + +TEST_F(JvmSupportNonHotspotTest, PreJni19ThreadIsStillAccepted) { + jni_version = 0x000a0000; + EXPECT_TRUE(JVMSupport::isPlatformThread(&jni, thread)); + EXPECT_EQ(0, is_virtual_thread_calls); +} + // --------------------------------------------------------------------------- // ProfilerTestAccessor — friend of Profiler, lets tests force the internal // state machine to a known value so checkState()/start()/check() can be diff --git a/ddprof-lib/src/test/cpp/park_state_ut.cpp b/ddprof-lib/src/test/cpp/park_state_ut.cpp index ff60f49e52..42fa453a16 100644 --- a/ddprof-lib/src/test/cpp/park_state_ut.cpp +++ b/ddprof-lib/src/test/cpp/park_state_ut.cpp @@ -40,9 +40,10 @@ TestProfiledThread testThread(int tid) { } // namespace -// Tests cover FLAG_PARKED lifecycle and the once-per-run slot filter state transitions. -// The slot state lives in ThreadFilter process-lifetime storage so the wall-clock -// timer can read it without dereferencing per-thread objects from another thread. +// Tests cover FLAG_PARKED lifecycle and owned-block slot state transitions. +// The slot state lives in WallClockBlockTracker process-lifetime storage so the +// wall-clock timer can read it without dereferencing per-thread objects from +// another thread. TEST(ProfiledThreadParkStateTest, ParkFlagLifecycle) { TestProfiledThread thread = testThread(12345); @@ -138,48 +139,18 @@ TEST(ProfiledThreadParkStateTest, ParkExitReturnsZeroTokenWhenBlockRunWasNotArme EXPECT_EQ(0ULL, park_block_token); } -TEST(WallClockOncePerRunFilterTest, SlotStateTransitions) { +TEST(WallClockOwnedBlockFilterTest, SlotStateTransitions) { WallClockBlockTracker::BlockState slot; - EXPECT_FALSE(slot.sampledThisRun()); - EXPECT_EQ(OSThreadState::UNKNOWN, slot.lastSampledState()); EXPECT_EQ(OSThreadState::UNKNOWN, slot.activeBlockState()); - // First signal: arm. slot.setActiveBlockState(OSThreadState::SLEEPING); - slot.markSampledThisRun(OSThreadState::SLEEPING); - EXPECT_TRUE(slot.sampledThisRun()); - EXPECT_EQ(OSThreadState::SLEEPING, slot.lastSampledState()); EXPECT_EQ(OSThreadState::SLEEPING, slot.activeBlockState()); - // Same state again: suppress (flag + state both match). - EXPECT_TRUE(slot.sampledThisRun() && - OSThreadState::SLEEPING == slot.lastSampledState()); - EXPECT_TRUE(slot.sampledThisRun() && - slot.activeBlockState() == slot.lastSampledState()); - - // Transition within skip set (SLEEPING -> CONDVAR_WAIT): state mismatch -> re-arm. slot.setActiveBlockState(OSThreadState::CONDVAR_WAIT); - EXPECT_FALSE(slot.sampledThisRun() && - OSThreadState::CONDVAR_WAIT == slot.lastSampledState()); - slot.markSampledThisRun(OSThreadState::CONDVAR_WAIT); - EXPECT_TRUE(slot.sampledThisRun()); - EXPECT_EQ(OSThreadState::CONDVAR_WAIT, slot.lastSampledState()); - EXPECT_TRUE(slot.sampledThisRun() && - slot.activeBlockState() == slot.lastSampledState()); - - // Leave skip set: reset -> next blocked entry re-arms. + EXPECT_EQ(OSThreadState::CONDVAR_WAIT, slot.activeBlockState()); slot.setActiveBlockState(OSThreadState::UNKNOWN); - slot.resetSampledRun(OSThreadState::RUNNABLE); - EXPECT_FALSE(slot.sampledThisRun()); - EXPECT_EQ(OSThreadState::RUNNABLE, slot.lastSampledState()); EXPECT_EQ(OSThreadState::UNKNOWN, slot.activeBlockState()); - - slot.setActiveBlockState(OSThreadState::SLEEPING); - slot.markSampledThisRun(OSThreadState::SLEEPING); - EXPECT_TRUE(slot.sampledThisRun()); - EXPECT_EQ(OSThreadState::SLEEPING, slot.lastSampledState()); - EXPECT_EQ(OSThreadState::SLEEPING, slot.activeBlockState()); } TEST(WallClockOncePerRunFilterTest, UnownedBlockedFallbackCarriesWeight) { @@ -335,20 +306,12 @@ TEST(WallClockOncePerRunFilterTest, FilterHelpersManageActiveBlockState) { ASSERT_NE(nullptr, slot); EXPECT_EQ(OSThreadState::CONDVAR_WAIT, slot->activeBlockState()); - slot->markSampledThisRun(OSThreadState::CONDVAR_WAIT); - EXPECT_TRUE(slot->sampledThisRun()); - EXPECT_TRUE(slot->sampledThisRun() && - slot->activeBlockState() == slot->lastSampledState()); - tracker.exitBlockedRun(slot_id); EXPECT_EQ(OSThreadState::UNKNOWN, slot->activeBlockState()); - EXPECT_FALSE(slot->sampledThisRun()); - EXPECT_EQ(OSThreadState::RUNNABLE, slot->lastSampledState()); + EXPECT_EQ(0ULL, slot->sampledBlockGeneration()); } -// Slot reuse: stale armed state from the previous owner must be cleared before -// the new thread takes the slot (ThreadFilter::resetSlotRunState does this). -TEST(WallClockOncePerRunFilterTest, ResetClearsArmedFlagOnSlotReuse) { +TEST(WallClockOncePerRunFilterTest, ResetClearsOwnedBlockOnSlotReuse) { ThreadFilter filter; WallClockBlockTracker tracker; filter.setBlockTracker(&tracker); @@ -357,13 +320,12 @@ TEST(WallClockOncePerRunFilterTest, ResetClearsArmedFlagOnSlotReuse) { tracker.enterBlockedRun(&filter, slot_id, OSThreadState::CONDVAR_WAIT); WallClockBlockTracker::BlockState *slot = tracker.slotForId(slot_id); ASSERT_NE(nullptr, slot); - slot->markSampledThisRun(OSThreadState::CONDVAR_WAIT); - EXPECT_TRUE(slot->sampledThisRun()); EXPECT_EQ(OSThreadState::CONDVAR_WAIT, slot->activeBlockState()); + slot->markBlockGenerationSampled(slot->blockGeneration()); + ASSERT_EQ(slot->blockGeneration(), slot->sampledBlockGeneration()); filter.resetSlotRunState(slot_id); - EXPECT_FALSE(slot->sampledThisRun()); - EXPECT_EQ(OSThreadState::UNKNOWN, slot->lastSampledState()); EXPECT_EQ(OSThreadState::UNKNOWN, slot->activeBlockState()); + EXPECT_EQ(0ULL, slot->sampledBlockGeneration()); } diff --git a/ddprof-lib/src/test/cpp/taskBlockRecorder_ut.cpp b/ddprof-lib/src/test/cpp/taskBlockRecorder_ut.cpp new file mode 100644 index 0000000000..ba6bbf2643 --- /dev/null +++ b/ddprof-lib/src/test/cpp/taskBlockRecorder_ut.cpp @@ -0,0 +1,299 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +#include + +#include "counters.h" +#include "profiler.h" +#include "taskBlockRecorder.h" +#include "tsc.h" + +#include +#include +#include +#include +#include + +namespace { + +std::atomic g_record_result{ + Profiler::TaskBlockRecordResult::RECORDED}; +std::atomic g_record_calls{0}; + +Profiler::TaskBlockRecordResult recordTaskBlockForTest( + int tid, jthread thread, int start_depth, TaskBlockEvent* event) { + g_record_calls.fetch_add(1, std::memory_order_relaxed); + return g_record_result.load(std::memory_order_acquire); +} + +u64 minEligibleEndTicks(u64 start_ticks) { + u64 low = start_ticks + 1; + u64 high = low; + while (!exceedsMinTaskBlockDuration(start_ticks, high)) { + high = start_ticks + ((high - start_ticks) * 2); + } + while (low < high) { + u64 mid = low + ((high - low) / 2); + if (exceedsMinTaskBlockDuration(start_ticks, mid)) { + high = mid; + } else { + low = mid + 1; + } + } + return low; +} + +class TaskBlockRecorderTest : public ::testing::Test { +protected: + void SetUp() override { + Counters::reset(); + initializeTaskBlockDurationThreshold(); + g_record_result.store(Profiler::TaskBlockRecordResult::RECORDED, + std::memory_order_release); + g_record_calls.store(0, std::memory_order_relaxed); + Profiler::setTaskBlockRecordOverrideForTest(recordTaskBlockForTest); + } + + void TearDown() override { + Profiler::setTaskBlockRecordOverrideForTest(nullptr); + Counters::reset(); + } +}; + +} // namespace + +TEST_F(TaskBlockRecorderTest, TraceContextIsRejectedBeforeDuration) { + Context context{}; + context.spanId = 123; + + EXPECT_FALSE(taskBlockPassesBasicEligibility(100, 100, context)); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_SKIPPED_TRACE_CONTEXT)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_SKIPPED_TOO_SHORT)); +} + +TEST_F(TaskBlockRecorderTest, DurationThresholdIncludesExactBoundary) { + Context context{}; + u64 start_ticks = TSC::ticks(); + u64 passing_end = minEligibleEndTicks(start_ticks); + + EXPECT_TRUE(taskBlockPassesBasicEligibility( + start_ticks, passing_end, context)); + EXPECT_FALSE(taskBlockPassesBasicEligibility( + start_ticks, passing_end - 1, context)); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_SKIPPED_TOO_SHORT)); +} + +TEST_F(TaskBlockRecorderTest, RotationRejectsNewActivity) { + Profiler* profiler = Profiler::instance(); + profiler->beginTaskBlockRotationForTest(); + + EXPECT_FALSE(profiler->tryEnterTaskBlockActivity()); + TaskBlockActivity activity; + EXPECT_FALSE(activity.active()); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_DROPPED_ROTATION)); + + profiler->endTaskBlockRotationForTest(); + ASSERT_TRUE(profiler->tryEnterTaskBlockActivity()); + profiler->leaveTaskBlockActivity(); +} + +TEST_F(TaskBlockRecorderTest, RotationWaitsForInflightActivity) { + Profiler* profiler = Profiler::instance(); + ASSERT_TRUE(profiler->tryEnterTaskBlockActivity()); + ASSERT_EQ(1, profiler->taskBlockInflightForTest()); + + std::atomic rotation_returned{false}; + std::thread rotation([&]() { + profiler->beginTaskBlockRotationForTest(); + rotation_returned.store(true, std::memory_order_release); + profiler->endTaskBlockRotationForTest(); + }); + + auto deadline = std::chrono::steady_clock::now() + std::chrono::seconds(5); + while (!profiler->taskBlockRotationActiveForTest() && + std::chrono::steady_clock::now() < deadline) { + std::this_thread::yield(); + } + + bool rotation_active = profiler->taskBlockRotationActiveForTest(); + EXPECT_TRUE(rotation_active); + EXPECT_EQ(1, profiler->taskBlockInflightForTest()); + EXPECT_FALSE(rotation_returned.load(std::memory_order_acquire)); + if (rotation_active) { + bool entered = profiler->tryEnterTaskBlockActivity(); + EXPECT_FALSE(entered); + if (entered) profiler->leaveTaskBlockActivity(); + } + + profiler->leaveTaskBlockActivity(); + rotation.join(); + + EXPECT_TRUE(rotation_returned.load(std::memory_order_acquire)); + EXPECT_FALSE(profiler->taskBlockRotationActiveForTest()); + EXPECT_EQ(0, profiler->taskBlockInflightForTest()); + ASSERT_TRUE(profiler->tryEnterTaskBlockActivity()); + profiler->leaveTaskBlockActivity(); +} + +TEST_F(TaskBlockRecorderTest, RotationTimesOutOnStuckInflightActivity) { + Profiler* profiler = Profiler::instance(); + ASSERT_TRUE(profiler->tryEnterTaskBlockActivity()); // leaked on purpose: simulates a stuck recorder + ASSERT_EQ(1, profiler->taskBlockInflightForTest()); + + auto start = std::chrono::steady_clock::now(); + bool result = profiler->beginTaskBlockRotationForTest(); + auto elapsed = std::chrono::steady_clock::now() - start; + + EXPECT_FALSE(result); + // Lower bound is deliberately looser than the 200ms timeout to avoid flakiness + // from clock/scheduling jitter around the deadline boundary. + EXPECT_GE(elapsed, std::chrono::milliseconds(150)); + EXPECT_LT(elapsed, std::chrono::milliseconds(2000)); // sanity bound, not a tight timing assertion + EXPECT_FALSE(profiler->taskBlockRotationActiveForTest()); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_ROTATION_TIMEOUT)); + + profiler->leaveTaskBlockActivity(); // clean up the leaked inflight count for later tests + ASSERT_EQ(0, profiler->taskBlockInflightForTest()); +} + +TEST_F(TaskBlockRecorderTest, RotationRejectsEndWithoutStrandingLifecycle) { + constexpr int tid = 12345; + ThreadFilter filter; + WallClockBlockTracker tracker; + filter.setBlockTracker(&tracker); + filter.init("", true); + ThreadFilter::SlotID slot_id = filter.registerThread(tid); + ASSERT_GE(slot_id, 0); + + std::unique_ptr current( + ProfiledThread::forTid(tid), ProfiledThread::deleteForTest); + current->setFilterSlotId(slot_id); + u64 token = tracker.enterBlockedRun( + &filter, slot_id, OSThreadState::SLEEPING, BlockRunOwner::JAVA); + ASSERT_NE(0ULL, token); + Context context{}; + ASSERT_TRUE(current->taskBlockEnter(token, TSC::ticks(), context)); + + Profiler* profiler = Profiler::instance(); + profiler->beginTaskBlockRotationForTest(); + std::future result = std::async(std::launch::async, [&]() { + return recordTaskBlockAtExit( + current.get(), &filter, &tracker, nullptr, 1, token, 0, 0); + }); + + std::future_status status = result.wait_for(std::chrono::seconds(1)); + bool returned_during_rotation = status == std::future_status::ready; + EXPECT_TRUE(returned_during_rotation); + if (returned_during_rotation) { + WallClockBlockTracker::BlockState* slot = tracker.slotForId(slot_id); + EXPECT_NE(nullptr, slot); + if (slot != nullptr) { + EXPECT_EQ(BlockRunOwner::NONE, slot->activeBlockOwner()); + EXPECT_EQ(OSThreadState::UNKNOWN, slot->activeBlockState()); + } + + u64 next_token = tracker.enterBlockedRun( + &filter, slot_id, OSThreadState::SLEEPING, BlockRunOwner::JAVA); + EXPECT_NE(0ULL, next_token); + EXPECT_TRUE(current->taskBlockEnter(next_token, TSC::ticks(), context)); + u64 ignored_ticks = 0; + Context ignored_context{}; + EXPECT_TRUE(current->taskBlockExit( + next_token, ignored_ticks, ignored_context)); + EXPECT_TRUE(tracker.exitBlockedRun( + slot_id, WallClockBlockTracker::tokenGeneration(next_token))); + } + + profiler->endTaskBlockRotationForTest(); + EXPECT_FALSE(result.get()); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_DROPPED_ROTATION)); +} + +TEST_F(TaskBlockRecorderTest, StaleCachedFilterSlotIsSelfHealedBeforeExit) { + constexpr int tid1 = 22101; + constexpr int tid2 = 22102; + ThreadFilter filter; + WallClockBlockTracker tracker; + filter.setBlockTracker(&tracker); + filter.init("", true); + ThreadFilter::SlotID slot1 = filter.registerThread(tid1); + ThreadFilter::SlotID slot2 = filter.registerThread(tid2); + ASSERT_GE(slot1, 0); + ASSERT_GE(slot2, 0); + ASSERT_NE(slot1, slot2); + + std::unique_ptr current( + ProfiledThread::forTid(tid1), ProfiledThread::deleteForTest); + current->setFilterSlotId(slot1); + + u64 token = tracker.enterBlockedRun( + &filter, slot1, OSThreadState::SLEEPING, BlockRunOwner::JAVA); + ASSERT_NE(0ULL, token); + + // Simulate a TLS cache that drifted away from the slot that actually holds + // this tid's live block run, e.g. another code path re-registered tid1's + // central registry entry without updating this thread's own TLS cache. + current->setFilterSlotId(slot2); + + Context context{}; + u64 start_ticks = TSC::ticks(); + finishTaskBlockAtExit(current.get(), &filter, &tracker, nullptr, 0, token, + start_ticks, context, 0, 0); + + EXPECT_EQ(slot1, current->filterSlotId()) + << "a stale cached slot must be self-healed back to the registry's " + "actual slot for this tid before being compared against the token"; + WallClockBlockTracker::BlockState* slot = tracker.slotForId(slot1); + ASSERT_NE(nullptr, slot); + EXPECT_EQ(BlockRunOwner::NONE, slot->activeBlockOwner()) + << "the live block run must still be cleared once the stale slot is " + "healed, instead of being stranded by a spurious slot mismatch"; +} + +TEST_F(TaskBlockRecorderTest, StackCaptureFailureIsCountedAndActivityReleased) { + g_record_result.store(Profiler::TaskBlockRecordResult::STACK_CAPTURE_FAILED, + std::memory_order_release); + Context context{}; + u64 start_ticks = TSC::ticks(); + u64 end_ticks = minEligibleEndTicks(start_ticks); + + EXPECT_FALSE(recordTaskBlockIfEligible( + 123, nullptr, 0, start_ticks, end_ticks, context, 0, 0, + OSThreadState::SLEEPING)); + + EXPECT_EQ(1, g_record_calls.load(std::memory_order_relaxed)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_EMITTED)); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_STACK_CAPTURE_FAILED)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_RECORD_FAILED)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_SKIPPED_TRACE_CONTEXT)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_SKIPPED_TOO_SHORT)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_DROPPED_ROTATION)); + EXPECT_EQ(0, Profiler::instance()->taskBlockInflightForTest()); + ASSERT_TRUE(Profiler::instance()->tryEnterTaskBlockActivity()); + Profiler::instance()->leaveTaskBlockActivity(); +} + +TEST_F(TaskBlockRecorderTest, RecordFailureIsCountedAndActivityReleased) { + g_record_result.store(Profiler::TaskBlockRecordResult::RECORD_FAILED, + std::memory_order_release); + Context context{}; + u64 start_ticks = TSC::ticks(); + u64 end_ticks = minEligibleEndTicks(start_ticks); + + EXPECT_FALSE(recordTaskBlockIfEligible( + 123, nullptr, 0, start_ticks, end_ticks, context, 0, 0, + OSThreadState::SLEEPING)); + + EXPECT_EQ(1, g_record_calls.load(std::memory_order_relaxed)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_EMITTED)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_STACK_CAPTURE_FAILED)); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_RECORD_FAILED)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_SKIPPED_TRACE_CONTEXT)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_SKIPPED_TOO_SHORT)); + EXPECT_EQ(0, Counters::getCounter(TASK_BLOCK_DROPPED_ROTATION)); + EXPECT_EQ(0, Profiler::instance()->taskBlockInflightForTest()); + ASSERT_TRUE(Profiler::instance()->tryEnterTaskBlockActivity()); + Profiler::instance()->leaveTaskBlockActivity(); +} diff --git a/ddprof-lib/src/test/cpp/threadFilter_ut.cpp b/ddprof-lib/src/test/cpp/threadFilter_ut.cpp index 525caa0ac4..0c477c9b90 100644 --- a/ddprof-lib/src/test/cpp/threadFilter_ut.cpp +++ b/ddprof-lib/src/test/cpp/threadFilter_ut.cpp @@ -466,7 +466,6 @@ TEST_F(ThreadFilterTest, ClearActiveDropsPreviousRecordingMembership) { tracker->enterBlockedRun(filter.get(), stale_slot, OSThreadState::SLEEPING); WallClockBlockTracker::BlockState *stale = tracker->slotForId(stale_slot); ASSERT_NE(nullptr, stale); - stale->markSampledThisRun(OSThreadState::SLEEPING); filter->clearActive(); @@ -475,8 +474,6 @@ TEST_F(ThreadFilterTest, ClearActiveDropsPreviousRecordingMembership) { EXPECT_TRUE(collected_tids.empty()); EXPECT_FALSE(filter->accept(stale_slot)); EXPECT_FALSE(filter->accept(current_slot)); - EXPECT_FALSE(stale->sampledThisRun()); - EXPECT_EQ(OSThreadState::UNKNOWN, stale->lastSampledState()); EXPECT_EQ(OSThreadState::UNKNOWN, stale->activeBlockState()); filter->add(2222, current_slot); @@ -485,20 +482,9 @@ TEST_F(ThreadFilterTest, ClearActiveDropsPreviousRecordingMembership) { EXPECT_EQ(2222, collected_tids[0]); } -// GenerationCheckedExitDoesNotClearAnotherOwner and NewGenerationRejectsStaleToken -// moved to wallClockBlockTracker_ut.cpp - they exercise pure WallClockBlockTracker -// generation-token behavior with no ThreadFilter-identity interaction. - -TEST_F(ThreadFilterTest, TokenRoundTripPreservesHighGenerationBit) { - ThreadFilter::SlotID slot_id = 7; - u32 generation = 0x80000001u; - u64 token = WallClockBlockTracker::encodeBlockRunToken(slot_id, generation); - int64_t java_token = static_cast(token); - - EXPECT_LT(java_token, 0); - EXPECT_EQ(slot_id, WallClockBlockTracker::tokenSlotId(static_cast(java_token))); - EXPECT_EQ(generation, WallClockBlockTracker::tokenGeneration(static_cast(java_token))); -} +// Generation-token, saturation, snapshot and owned-block decision tests live in +// wallClockBlockTracker_ut.cpp - they exercise WallClockBlockTracker behavior +// rather than ThreadFilter identity. class ThreadRegistryTest : public ::testing::Test { protected: @@ -541,6 +527,26 @@ TEST_F(ThreadRegistryTest, UnfilteredTrackingSeparatesRegistrationFromContextWin EXPECT_TRUE(context.empty()); } +TEST_F(ThreadRegistryTest, LookupThreadEntryDoesNotRegisterUnknownTid) { + constexpr int tid = 3210; + ThreadEntry entry{tid, nullptr, -1, 0, 0}; + + EXPECT_FALSE(registry.lookupThreadEntry(entry, registry.recordingEpoch())); + EXPECT_EQ(nullptr, entry.slot); + EXPECT_EQ(nullptr, registry.lookupByTid(tid)); + + int slot_id = registry.registerThread(tid); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = registry.slotForId(slot_id); + ASSERT_NE(nullptr, slot); + + EXPECT_TRUE(registry.lookupThreadEntry(entry, registry.recordingEpoch())); + EXPECT_EQ(slot, entry.slot); + EXPECT_EQ(slot_id, entry.slot_id); + EXPECT_EQ(slot->lifecycleGeneration(), entry.lifecycle_generation); + EXPECT_EQ(slot->recordingEpoch(), entry.recording_epoch); +} + TEST_F(ThreadRegistryTest, RegisteringKnownTidReturnsExistingSlotWithoutMutation) { constexpr int tid = 4321; int slot_id = registry.registerThread(tid); @@ -552,14 +558,13 @@ TEST_F(ThreadRegistryTest, RegisteringKnownTidReturnsExistingSlotWithoutMutation ASSERT_NE(0ULL, token); WallClockBlockTracker::BlockState* block_slot = tracker.slotForId(slot_id); ASSERT_NE(nullptr, block_slot); - block_slot->markSampledThisRun(OSThreadState::SLEEPING); u64 lifecycle_generation = slot->lifecycleGeneration(); EXPECT_EQ(slot_id, registry.registerThread(tid)); EXPECT_EQ(slot, registry.lookupByTid(tid)); EXPECT_EQ(lifecycle_generation, slot->lifecycleGeneration()); EXPECT_EQ(OSThreadState::SLEEPING, block_slot->activeBlockState()); - EXPECT_TRUE(block_slot->sampledThisRun()); + EXPECT_EQ(BlockRunOwner::JAVA, block_slot->activeBlockOwner()); EXPECT_TRUE(tracker.exitBlockedRun( slot_id, WallClockBlockTracker::tokenGeneration(token))); } @@ -757,7 +762,6 @@ TEST_F(ThreadRegistryTest, ContextTransitionInvalidatesOwnedRunSuppression) { ASSERT_NE(0u, token); WallClockBlockTracker::BlockState* block_slot = tracker.slotForId(slot_id); ASSERT_NE(nullptr, block_slot); - block_slot->markSampledThisRun(OSThreadState::SLEEPING); EXPECT_TRUE(block_slot->activeBlockRemainedOutsideContextWindow(slot)); registry.add(3333, slot_id); @@ -766,7 +770,7 @@ TEST_F(ThreadRegistryTest, ContextTransitionInvalidatesOwnedRunSuppression) { ThreadEntry entry{3333, slot, slot_id, slot->lifecycleGeneration(), slot->recordingEpoch()}; - EXPECT_FALSE(tracker.shouldSuppressOwnedBlock(®istry, entry)); + EXPECT_FALSE(tracker.isOwnedBlockSuppressionCandidate(®istry, entry)); } TEST_F(ThreadRegistryTest, UnfilteredSuppressionValidatesIdentityAndLifecycle) { @@ -779,24 +783,24 @@ TEST_F(ThreadRegistryTest, UnfilteredSuppressionValidatesIdentityAndLifecycle) { ASSERT_NE(0u, token); WallClockBlockTracker::BlockState* block_slot = tracker.slotForId(slot_id); ASSERT_NE(nullptr, block_slot); - block_slot->markSampledThisRun(OSThreadState::SLEEPING); + block_slot->markBlockGenerationSampled(WallClockBlockTracker::tokenGeneration(token)); ThreadEntry entry{4444, slot, slot_id, slot->lifecycleGeneration(), slot->recordingEpoch()}; - EXPECT_TRUE(tracker.shouldSuppressOwnedBlock(®istry, entry)); + EXPECT_TRUE(tracker.isOwnedBlockSuppressionCandidate(®istry, entry)); ThreadEntry wrong_tid{4445, slot, slot_id, entry.lifecycle_generation, entry.recording_epoch}; - EXPECT_FALSE(tracker.shouldSuppressOwnedBlock(®istry, wrong_tid)); + EXPECT_FALSE(tracker.isOwnedBlockSuppressionCandidate(®istry, wrong_tid)); ThreadEntry stale_generation{4444, slot, slot_id, entry.lifecycle_generation + 1, entry.recording_epoch}; - EXPECT_FALSE(tracker.shouldSuppressOwnedBlock(®istry, stale_generation)); + EXPECT_FALSE(tracker.isOwnedBlockSuppressionCandidate(®istry, stale_generation)); EXPECT_TRUE(tracker.exitBlockedRun( slot_id, WallClockBlockTracker::tokenGeneration(token))); - EXPECT_FALSE(tracker.shouldSuppressOwnedBlock(®istry, entry)); + EXPECT_FALSE(tracker.isOwnedBlockSuppressionCandidate(®istry, entry)); } -TEST_F(ThreadRegistryTest, ContextFilteredSuppressionPreservesHistoricalEligibility) { +TEST_F(ThreadRegistryTest, ContextFilteredSuppressionRemainsDisabled) { registry.init("0"); int slot_id = registry.registerThread(5555); ASSERT_GE(slot_id, 0); @@ -808,10 +812,9 @@ TEST_F(ThreadRegistryTest, ContextFilteredSuppressionPreservesHistoricalEligibil ASSERT_NE(0u, token); WallClockBlockTracker::BlockState* block_slot = tracker.slotForId(slot_id); ASSERT_NE(nullptr, block_slot); - block_slot->markSampledThisRun(OSThreadState::SLEEPING); ThreadEntry entry{5555, slot, slot_id, slot->lifecycleGeneration(), slot->recordingEpoch()}; - EXPECT_TRUE(tracker.shouldSuppressOwnedBlock(®istry, entry)); + EXPECT_FALSE(tracker.isOwnedBlockSuppressionCandidate(®istry, entry)); } TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { @@ -820,8 +823,10 @@ TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { ASSERT_GE(slot_id, 0); ThreadFilter::Slot* slot = registry.slotForId(slot_id); ASSERT_NE(nullptr, slot); - ASSERT_NE(0u, tracker.enterBlockedRun(®istry, slot_id, OSThreadState::SLEEPING)); - tracker.slotForId(slot_id)->markSampledThisRun(OSThreadState::SLEEPING); + u64 token = tracker.enterBlockedRun(®istry, slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0u, token); + tracker.slotForId(slot_id)->markBlockGenerationSampled( + WallClockBlockTracker::tokenGeneration(token)); ThreadEntry stale{tid, slot, slot_id, slot->lifecycleGeneration(), slot->recordingEpoch()}; @@ -841,7 +846,7 @@ TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { std::atomic suppressed{true}; std::thread reader([&] { - suppressed.store(tracker.shouldSuppressOwnedBlock(®istry, stale), + suppressed.store(tracker.isOwnedBlockSuppressionCandidate(®istry, stale), std::memory_order_release); }); auto deadline = std::chrono::steady_clock::now() + std::chrono::seconds(5); @@ -860,9 +865,6 @@ TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { int reused_id = registry.registerThread(tid); ThreadFilter::Slot* reused = registry.slotForId(reused_id); u64 new_token = tracker.enterBlockedRun(®istry, reused_id, OSThreadState::SLEEPING); - if (reused != nullptr && new_token != 0) { - tracker.slotForId(reused_id)->markSampledThisRun(OSThreadState::SLEEPING); - } pause.resume.store(true, std::memory_order_release); reader.join(); @@ -1117,10 +1119,11 @@ TEST_F(ThreadRegistryTest, NewUnfilteredRecordingRetainsIdentityAndRefreshesPayl u64 token = tracker.enterBlockedRun(®istry, slot_id, OSThreadState::SLEEPING); ASSERT_NE(0u, token); - tracker.slotForId(slot_id)->markSampledThisRun(OSThreadState::SLEEPING); + tracker.slotForId(slot_id)->markBlockGenerationSampled( + WallClockBlockTracker::tokenGeneration(token)); ThreadEntry stale{tid, slot, slot_id, slot->lifecycleGeneration(), slot->recordingEpoch()}; - ASSERT_TRUE(tracker.shouldSuppressOwnedBlock(®istry, stale)); + ASSERT_TRUE(tracker.isOwnedBlockSuppressionCandidate(®istry, stale)); registry.init("", true); ThreadFilter::RecordingEpoch second_epoch = registry.recordingEpoch(); @@ -1131,12 +1134,12 @@ TEST_F(ThreadRegistryTest, NewUnfilteredRecordingRetainsIdentityAndRefreshesPayl EXPECT_EQ(tid, slot->nativeTid()); EXPECT_EQ(first_lifecycle_generation, slot->lifecycleGeneration()); EXPECT_EQ(nullptr, registry.activeSlotForId(slot_id, tid)); - EXPECT_FALSE(tracker.shouldSuppressOwnedBlock(®istry, stale)); + EXPECT_FALSE(tracker.isOwnedBlockSuppressionCandidate(®istry, stale)); EXPECT_EQ(slot_id, registry.registerThread(tid)); EXPECT_EQ(slot, registry.lookupByTid(tid, second_epoch)); WallClockBlockTracker::BlockState* block_slot = tracker.slotForId(slot_id); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); } diff --git a/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp b/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp index 5c00a2e265..fcc623c5c9 100644 --- a/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp +++ b/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp @@ -156,11 +156,11 @@ TEST_P(WallClockBlockRestartTest, PausedHookDoesNotMutateReplacementAcrossRestar // Model only successful sample completion, as finishWallPrecheck() does. // Admission and the stale caller's exit above use the actual JNI bodies. if (block->activeBlockOwner() != BlockRunOwner::NONE) { - block->markSampledThisRun(hookState()); + block->markBlockGenerationSampled(block->blockGeneration()); } ThreadEntry replacement{current->tid(), identity, replacement_slot, identity->lifecycleGeneration(), identity->recordingEpoch()}; - EXPECT_FALSE(tracker->shouldSuppressOwnedBlock(registry, replacement)) + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(registry, replacement)) << "A thread that never entered a block became suppressible"; // A bogus active run must also not prevent the new owner arming its own run. @@ -183,16 +183,16 @@ TEST_P(WallClockBlockRestartTest, SurvivingOwnerRefreshesOnlyRecordingState) { auto* block = tracker->slotForId(slot_id); u64 generation = identity->lifecycleGeneration(); u64 epoch = registry->recordingEpoch(); - block->markSampledThisRun(hookState()); + block->markBlockGenerationSampled(block->blockGeneration()); ThreadEntry stale{current->tid(), identity, slot_id, generation, epoch}; - ASSERT_TRUE(tracker->shouldSuppressOwnedBlock(registry, stale)); + ASSERT_TRUE(tracker->isOwnedBlockSuppressionCandidate(registry, stale)); registry->deactivateRecording(); registry->init("", true); ASSERT_EQ(identity, registry->lookupByTid(current->tid())); EXPECT_EQ(generation, identity->lifecycleGeneration()); EXPECT_EQ(nullptr, registry->activeSlotForId(slot_id, current->tid())); - EXPECT_FALSE(tracker->shouldSuppressOwnedBlock(registry, stale)); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(registry, stale)); exitHook(old_token); u64 new_token = enterHook(); @@ -200,7 +200,7 @@ TEST_P(WallClockBlockRestartTest, SurvivingOwnerRefreshesOnlyRecordingState) { EXPECT_NE(old_token, new_token); EXPECT_EQ(slot_id, current->filterSlotId()); EXPECT_EQ(registry->recordingEpoch(), identity->recordingEpoch()); - EXPECT_FALSE(block->sampledThisRun()); + EXPECT_EQ(0ULL, block->sampledBlockGeneration()); EXPECT_EQ(hookState(), block->activeBlockState()); exitHook(new_token); } diff --git a/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp b/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp index aaad0a4897..f2ca80c16d 100644 --- a/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp +++ b/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp @@ -18,8 +18,10 @@ #include "nativeMem.h" #include "threadFilter.h" #include "wallClockBlockTracker.h" +#include "counters.h" #include "../../main/cpp/gtest_crash_handler.h" #include +#include // Test name for crash handler static constexpr char WALLCLOCK_BLOCK_TRACKER_TEST_NAME[] = "WallClockBlockTrackerTest"; @@ -40,6 +42,13 @@ class WallClockBlockTrackerTest : public ::testing::Test { restoreDefaultSignalHandlers(); } + void markCurrentGenerationSampled(ThreadFilter::SlotID slot_id) { + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, block_slot); + block_slot->markBlockGenerationSampled(block_slot->blockGeneration()); + ASSERT_NE(0ULL, block_slot->sampledBlockGeneration()); + } + std::unique_ptr filter; std::unique_ptr tracker; }; @@ -96,7 +105,7 @@ TEST_F(WallClockBlockTrackerTest, RegisterThreadReuseResetsBlockState) { int slot_id = filter->registerThread(1001); ASSERT_GE(slot_id, 0); ASSERT_NE(0ULL, tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING)); - tracker->slotForId(slot_id)->markSampledThisRun(OSThreadState::SLEEPING); + markCurrentGenerationSampled(slot_id); filter->unregisterThread(slot_id); int reused_id = filter->registerThread(1002); @@ -104,7 +113,7 @@ TEST_F(WallClockBlockTrackerTest, RegisterThreadReuseResetsBlockState) { WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(reused_id); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); } @@ -114,7 +123,7 @@ TEST_F(WallClockBlockTrackerTest, RegisterThreadNewSlotStartsWithClearBlockState WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); ASSERT_NE(nullptr, block_slot); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); } @@ -122,13 +131,13 @@ TEST_F(WallClockBlockTrackerTest, UnregisterThreadResetsBlockState) { int slot_id = filter->registerThread(4001); ASSERT_GE(slot_id, 0); ASSERT_NE(0ULL, tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING)); - tracker->slotForId(slot_id)->markSampledThisRun(OSThreadState::SLEEPING); + markCurrentGenerationSampled(slot_id); filter->unregisterThread(slot_id); WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); } @@ -140,27 +149,27 @@ TEST_F(WallClockBlockTrackerTest, NewRecordingRefreshesBlockStateLazily) { int slot_id = registry.registerThread(5001); ASSERT_GE(slot_id, 0); ASSERT_NE(0u, tracker->enterBlockedRun(®istry, slot_id, OSThreadState::SLEEPING)); - tracker->slotForId(slot_id)->markSampledThisRun(OSThreadState::SLEEPING); + markCurrentGenerationSampled(slot_id); ThreadFilter::Slot* identity = registry.slotForId(slot_id); ThreadEntry stale{5001, identity, slot_id, identity->lifecycleGeneration(), identity->recordingEpoch()}; - ASSERT_TRUE(tracker->shouldSuppressOwnedBlock(®istry, stale)); + ASSERT_TRUE(tracker->isOwnedBlockSuppressionCandidate(®istry, stale)); // Epoch invalidation makes retained payload ineligible before its owner // refreshes. No other thread resets an owner's live block state on restart. registry.init("", true); - EXPECT_FALSE(tracker->shouldSuppressOwnedBlock(®istry, stale)); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(®istry, stale)); EXPECT_EQ(identity, registry.lookupByTid(5001)); EXPECT_EQ(nullptr, registry.activeSlotForId(slot_id, 5001)); WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); EXPECT_EQ(OSThreadState::SLEEPING, block_slot->activeBlockState()); - EXPECT_TRUE(block_slot->sampledThisRun()); + EXPECT_NE(0ULL, block_slot->sampledBlockGeneration()); ASSERT_EQ(slot_id, registry.registerThread(5001)); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); } @@ -169,24 +178,290 @@ TEST_F(WallClockBlockTrackerTest, ClearActiveResetsBlockState) { ASSERT_GE(slot_id, 0); filter->add(6001, slot_id); ASSERT_NE(0ULL, tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING)); - tracker->slotForId(slot_id)->markSampledThisRun(OSThreadState::SLEEPING); + markCurrentGenerationSampled(slot_id); filter->clearActive(); WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); +} + +TEST_F(WallClockBlockTrackerTest, CollectUnownedBlockedTraceIdsFindsOnlyCachedSlots) { + int with_trace_id = filter->registerThread(7001); + int without_trace_id = filter->registerThread(7002); + ASSERT_GE(with_trace_id, 0); + ASSERT_GE(without_trace_id, 0); + + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(with_trace_id); + ASSERT_NE(nullptr, block_slot); + block_slot->recordUnownedBlockedSample(0xABCDULL, OSThreadState::SLEEPING); + + std::set collected; + tracker->collectUnownedBlockedTraceIds( + [&](u64 call_trace_id) { collected.insert(call_trace_id); }); + + EXPECT_EQ(collected.size(), 1u); + EXPECT_TRUE(collected.count(0xABCDULL)); +} + +TEST_F(WallClockBlockTrackerTest, SaturatedGenerationIsCountedAndRecoversAfterSlotReuse) { + int slot_id = filter->registerThread(3333); + ASSERT_GE(slot_id, 0); + filter->add(3333, slot_id); + + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, block_slot); + block_slot->setBlockGenerationForTest(WallClockBlockTracker::kMaxBlockRunGeneration); + +#ifdef COUNTERS + long long saturated_before = + Counters::getCounter(THREAD_REGISTRY_BLOCK_GENERATION_SATURATED); +#endif + EXPECT_EQ(0ULL, tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING)); +#ifdef COUNTERS + EXPECT_EQ(saturated_before + 1, + Counters::getCounter(THREAD_REGISTRY_BLOCK_GENERATION_SATURATED)); +#endif + + filter->unregisterThread(slot_id); + int reused_slot_id = filter->registerThread(3334); + ASSERT_EQ(slot_id, reused_slot_id) + << "test relies on the free list handing back the just-freed slot"; + filter->add(3334, reused_slot_id); + + EXPECT_EQ(0ULL, tracker->slotForId(reused_slot_id)->blockGeneration()); + + u64 token = tracker->enterBlockedRun(filter.get(), reused_slot_id, OSThreadState::SLEEPING); + EXPECT_NE(0ULL, token); + EXPECT_TRUE(tracker->exitBlockedRun(reused_slot_id, + WallClockBlockTracker::tokenGeneration(token))); +} + +TEST_F(WallClockBlockTrackerTest, UnregisterWhileBlockRunActiveIsCounted) { + int slot_id = filter->registerThread(4444); + ASSERT_GE(slot_id, 0); + filter->add(4444, slot_id); + + u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + +#ifdef COUNTERS + long long before = + Counters::getCounter(THREAD_REGISTRY_UNREGISTER_ACTIVE_BLOCK_RUN); +#endif + filter->unregisterThread(slot_id); +#ifdef COUNTERS + EXPECT_EQ(before + 1, + Counters::getCounter(THREAD_REGISTRY_UNREGISTER_ACTIVE_BLOCK_RUN)); +#endif +} + +TEST_F(WallClockBlockTrackerTest, TokenRoundTripPreservesNegativeJavaLongBitPattern) { + ThreadFilter::SlotID slot_id = 7; + u64 generation = 1ULL << 52; + u64 token = WallClockBlockTracker::encodeBlockRunToken(slot_id, generation); + int64_t java_token = static_cast(token); + + EXPECT_LT(java_token, 0); + ThreadFilter::SlotID decoded_slot = -1; + u64 decoded_generation = 0; + EXPECT_TRUE(WallClockBlockTracker::decodeBlockRunToken( + static_cast(java_token), decoded_slot, decoded_generation)); + EXPECT_EQ(slot_id, decoded_slot); + EXPECT_EQ(generation, decoded_generation); +} + +TEST_F(WallClockBlockTrackerTest, TokenRoundTripCoversSlotAndGenerationBoundaries) { + ThreadFilter::SlotID decoded_slot = -1; + u64 decoded_generation = 0; + + u64 first = WallClockBlockTracker::encodeBlockRunToken(0, 1); + ASSERT_TRUE(WallClockBlockTracker::decodeBlockRunToken( + first, decoded_slot, decoded_generation)); + EXPECT_EQ(0, decoded_slot); + EXPECT_EQ(1ULL, decoded_generation); + + u64 last = WallClockBlockTracker::encodeBlockRunToken( + ThreadFilter::kMaxThreads - 1, WallClockBlockTracker::kMaxBlockRunGeneration); + EXPECT_EQ(UINT64_MAX, last); + ASSERT_TRUE(WallClockBlockTracker::decodeBlockRunToken( + last, decoded_slot, decoded_generation)); + EXPECT_EQ(ThreadFilter::kMaxThreads - 1, decoded_slot); + EXPECT_EQ(WallClockBlockTracker::kMaxBlockRunGeneration, decoded_generation); + + EXPECT_FALSE(WallClockBlockTracker::decodeBlockRunToken( + 0, decoded_slot, decoded_generation)); + EXPECT_FALSE(WallClockBlockTracker::decodeBlockRunToken( + static_cast(ThreadFilter::kMaxThreads - 1), + decoded_slot, decoded_generation)); +} + +TEST_F(WallClockBlockTrackerTest, SaturatedGenerationRefusesEntryWithoutClaimingSlot) { + int slot_id = filter->registerThread(8001); + ASSERT_GE(slot_id, 0); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, block_slot); + block_slot->setBlockGenerationForTest(WallClockBlockTracker::kMaxBlockRunGeneration - 1); + + u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + EXPECT_EQ(WallClockBlockTracker::kMaxBlockRunGeneration, + WallClockBlockTracker::tokenGeneration(token)); + ASSERT_TRUE(tracker->exitBlockedRun( + slot_id, WallClockBlockTracker::tokenGeneration(token))); + + EXPECT_EQ(0ULL, tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING)); + EXPECT_EQ(0ULL, tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING)); + EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); + EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); + EXPECT_EQ(WallClockBlockTracker::kMaxBlockRunGeneration, block_slot->blockGeneration()); +} + +TEST_F(WallClockBlockTrackerTest, SnapshotCapturesOwnedLifecycle) { + int slot_id = filter->registerThread(8002); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* identity_slot = filter->slotForId(slot_id); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, identity_slot); + ASSERT_NE(nullptr, block_slot); + u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + + BlockRunSnapshot snapshot = block_slot->snapshotBlockRun(identity_slot); + EXPECT_EQ(OSThreadState::SLEEPING, snapshot.active_state); + + ASSERT_TRUE(tracker->snapshotAndExitBlockedRun( + filter.get(), slot_id, WallClockBlockTracker::tokenGeneration(token), &snapshot)); + EXPECT_EQ(OSThreadState::SLEEPING, snapshot.active_state); + EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->snapshotBlockRun(identity_slot).active_state); +} + +TEST_F(WallClockBlockTrackerTest, OwnedBlockSuppressesOnlyAfterSuccessfulWallSample) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + + ThreadEntry entry{1234, slot, slot_id, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + u64 generation = 0; + EXPECT_TRUE(tracker->activeOwnedBlockGeneration(filter.get(), entry, generation)); + EXPECT_EQ(WallClockBlockTracker::tokenGeneration(token), generation); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); + + block_slot->markBlockGenerationSampled(generation); + EXPECT_TRUE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate( + filter.get(), + {1235, slot, slot_id, slot->lifecycleGeneration(), slot->recordingEpoch()})); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate( + filter.get(), + {1234, slot, slot_id, slot->lifecycleGeneration() + 1, slot->recordingEpoch()})); + + ASSERT_TRUE(tracker->exitBlockedRun( + slot_id, WallClockBlockTracker::tokenGeneration(token))); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); +} + +TEST_F(WallClockBlockTrackerTest, ExitingOwnedBlockReenablesUnownedBlockedFallback) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, block_slot); + ASSERT_TRUE(block_slot->unownedBlockedFallbackEnabled()); + + u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + EXPECT_FALSE(block_slot->unownedBlockedFallbackEnabled()); + + ASSERT_TRUE(tracker->exitBlockedRun( + slot_id, WallClockBlockTracker::tokenGeneration(token))); + EXPECT_TRUE(block_slot->unownedBlockedFallbackEnabled()); +} + +TEST_F(WallClockBlockTrackerTest, StaleSampleCompletionCannotSuppressNewBlockGeneration) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + + u64 first_token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, first_token); + u64 first_generation = WallClockBlockTracker::tokenGeneration(first_token); + ASSERT_TRUE(tracker->exitBlockedRun(slot_id, first_generation)); + + u64 second_token = + tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::CONDVAR_WAIT); + ASSERT_NE(0ULL, second_token); + u64 second_generation = WallClockBlockTracker::tokenGeneration(second_token); + ASSERT_GT(second_generation, first_generation); + + ThreadEntry entry{1234, slot, slot_id, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + block_slot->markBlockGenerationSampled(first_generation); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); + + block_slot->markBlockGenerationSampled(second_generation); + EXPECT_TRUE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); + + // A delayed completion from the first run must not overwrite the newer mark. + block_slot->markBlockGenerationSampled(first_generation); + EXPECT_EQ(second_generation, block_slot->sampledBlockGeneration()); + EXPECT_TRUE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); +} + +TEST_F(WallClockBlockTrackerTest, ContextScopeNeverSuppressesOwnedBlock) { + filter->init("0", false); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + filter->add(1234, slot_id); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + ASSERT_NE(0ULL, tracker->enterBlockedRun( + filter.get(), slot_id, OSThreadState::CONDVAR_WAIT)); + + ThreadEntry entry{1234, slot, slot_id, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + block_slot->markBlockGenerationSampled(block_slot->blockGeneration()); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); +} + +TEST_F(WallClockBlockTrackerTest, ContextEpochDisablesOwnedBlockSuppression) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + ASSERT_NE(0ULL, tracker->enterBlockedRun( + filter.get(), slot_id, OSThreadState::CONDVAR_WAIT)); + ThreadEntry entry{1234, slot, slot_id, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + block_slot->markBlockGenerationSampled(block_slot->blockGeneration()); + ASSERT_TRUE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); + + filter->add(1234, slot_id); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); + filter->remove(slot_id); + EXPECT_FALSE(tracker->isOwnedBlockSuppressionCandidate(filter.get(), entry)); } // If a block/park run's matching exit is missed (e.g. an exception path with -// no finally/blockExit0), the slot stays "owned" forever and -// shouldSuppressOwnedBlock() keeps skipping the thread in every later -// context window. ThreadFilter::add() must clear a stuck active block run on -// every context-window entry, but must NOT reset the unrelated -// unowned-blocked sampling weight, which is meant to survive across -// context-window entries/exits to keep its amortized sampling ratio -// meaningful. -TEST_F(WallClockBlockTrackerTest, ContextEntryClearsStuckActiveBlockRunButPreservesUnownedWeight) { +// no finally/blockExit0), the slot stays "owned" forever and the owned-block +// suppression keeps skipping the thread in every later context window. +// ThreadFilter::add() must clear a stuck active block run on every +// context-window entry, and the stale token must not be able to close a +// later run. +TEST_F(WallClockBlockTrackerTest, ContextEntryClearsStuckActiveBlockRun) { constexpr int tid = 7001; int slot_id = filter->registerThread(tid); ASSERT_GE(slot_id, 0); @@ -195,18 +470,13 @@ TEST_F(WallClockBlockTrackerTest, ContextEntryClearsStuckActiveBlockRunButPreser // arrives. u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); ASSERT_NE(0ULL, token); + u64 generation = WallClockBlockTracker::tokenGeneration(token); WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); ASSERT_NE(nullptr, block_slot); - block_slot->markSampledThisRun(OSThreadState::SLEEPING); - ASSERT_TRUE(block_slot->sampledThisRun()); - - // Accumulate unowned-blocked fallback weight/state, independent of the - // owned block run above -- this must survive the context re-entry below. - EXPECT_TRUE(block_slot->shouldRecordUnownedBlockedSample()); - block_slot->recordUnownedBlockedSample(0xABCDULL, OSThreadState::CONDVAR_WAIT); - EXPECT_FALSE(block_slot->shouldRecordUnownedBlockedSample()); - EXPECT_FALSE(block_slot->shouldRecordUnownedBlockedSample()); + block_slot->markBlockGenerationSampled(generation); + ASSERT_EQ(generation, block_slot->sampledBlockGeneration()); + ASSERT_FALSE(block_slot->unownedBlockedFallbackEnabled()); // The thread re-enters the context window (filterThreadAdd0 -> add()) // while the stale block run is still "owned". @@ -214,18 +484,63 @@ TEST_F(WallClockBlockTrackerTest, ContextEntryClearsStuckActiveBlockRunButPreser EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); - EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->lastSampledState()); + EXPECT_EQ(0ULL, block_slot->sampledBlockGeneration()); + EXPECT_TRUE(block_slot->unownedBlockedFallbackEnabled()); + EXPECT_EQ(generation, block_slot->blockGeneration()); + + // The late exit for the cleared run is rejected, including after a new + // run has been opened on the same slot. + EXPECT_FALSE(tracker->exitBlockedRun(slot_id, generation)); + filter->remove(slot_id); + u64 next_token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, next_token); + EXPECT_GT(WallClockBlockTracker::tokenGeneration(next_token), generation); + EXPECT_FALSE(tracker->exitBlockedRun(slot_id, generation)); + EXPECT_NE(BlockRunOwner::NONE, block_slot->activeBlockOwner()); + EXPECT_TRUE(tracker->exitBlockedRun( + slot_id, WallClockBlockTracker::tokenGeneration(next_token))); +} - u64 call_trace_id = 0, weight = 0; - OSThreadState state = OSThreadState::UNKNOWN; - EXPECT_TRUE(block_slot->flushUnownedBlockedTail(call_trace_id, weight, state)); - EXPECT_EQ(0xABCDULL, call_trace_id); - EXPECT_EQ(2ULL, weight); - EXPECT_EQ(OSThreadState::CONDVAR_WAIT, state); +// Unlike a JAVA/JVMTI/NATIVE block/park run (see +// ContextEntryClearsStuckActiveBlockRun above), a TASK_BLOCK run is paired +// explicitly by beginTaskBlock0/endTaskBlock0 around caller-controlled code, +// so the owning thread calling add()/remove() mid-run is an expected +// crossing, not a stuck leak. Context entry must leave it intact so the +// eventual exit can tell a crossed run (ineligible, but found) from one that +// never started (not found at all) -- see +// JavaProfilerTaskBlockApiTest#contextWindowAdmissionAndCrossingAreEnforced. +TEST_F(WallClockBlockTrackerTest, ContextEntryPreservesActiveTaskBlockRunForCrossingDetection) { + constexpr int tid = 7003; + int slot_id = filter->registerThread(tid); + ASSERT_GE(slot_id, 0); + + u64 token = tracker->enterBlockedRun(filter.get(), slot_id, OSThreadState::SLEEPING, + BlockRunOwner::TASK_BLOCK); + ASSERT_NE(0ULL, token); + u64 generation = WallClockBlockTracker::tokenGeneration(token); + + WallClockBlockTracker::BlockState* block_slot = tracker->slotForId(slot_id); + ASSERT_NE(nullptr, block_slot); + + EXPECT_TRUE(filter->add(tid, slot_id)); + EXPECT_EQ(BlockRunOwner::TASK_BLOCK, block_slot->activeBlockOwner()) + << "context entry must not clear an in-flight TASK_BLOCK run"; + EXPECT_EQ(OSThreadState::SLEEPING, block_slot->activeBlockState()); + filter->remove(slot_id); + + BlockRunSnapshot snapshot; + EXPECT_TRUE(tracker->snapshotAndExitBlockedRun(filter.get(), slot_id, generation, + &snapshot)); + EXPECT_FALSE(snapshot.context_eligible) + << "a run that crossed a context-window entry/exit must be reported " + "ineligible instead of silently discarded"; + EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); } -TEST_F(WallClockBlockTrackerTest, ContextEntryWithoutActiveBlockRunIsANoop) { +// Without an owned run, context entry must not touch the unowned-blocked +// sampling weight, which is meant to survive across context-window +// entries/exits to keep its amortized sampling ratio meaningful. +TEST_F(WallClockBlockTrackerTest, ContextEntryWithoutActiveBlockRunPreservesUnownedWeight) { constexpr int tid = 7002; int slot_id = filter->registerThread(tid); ASSERT_GE(slot_id, 0); @@ -234,11 +549,23 @@ TEST_F(WallClockBlockTrackerTest, ContextEntryWithoutActiveBlockRunIsANoop) { ASSERT_NE(nullptr, block_slot); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); + EXPECT_TRUE(block_slot->shouldRecordUnownedBlockedSample()); + block_slot->recordUnownedBlockedSample(0xABCDULL, OSThreadState::CONDVAR_WAIT); + EXPECT_FALSE(block_slot->shouldRecordUnownedBlockedSample()); + EXPECT_FALSE(block_slot->shouldRecordUnownedBlockedSample()); + EXPECT_TRUE(filter->add(tid, slot_id)); EXPECT_EQ(BlockRunOwner::NONE, block_slot->activeBlockOwner()); EXPECT_EQ(OSThreadState::UNKNOWN, block_slot->activeBlockState()); - EXPECT_FALSE(block_slot->sampledThisRun()); + EXPECT_TRUE(block_slot->unownedBlockedFallbackEnabled()); + + u64 call_trace_id = 0, weight = 0; + OSThreadState state = OSThreadState::UNKNOWN; + EXPECT_TRUE(block_slot->flushUnownedBlockedTail(call_trace_id, weight, state)); + EXPECT_EQ(0xABCDULL, call_trace_id); + EXPECT_EQ(2ULL, weight); + EXPECT_EQ(OSThreadState::CONDVAR_WAIT, state); } // The ~128 KiB _slots array is an eager, unconditional allocation (unlike diff --git a/ddprof-lib/src/test/cpp/wallClockCounters_ut.cpp b/ddprof-lib/src/test/cpp/wallClockCounters_ut.cpp index c908b84fc7..7a6482d45a 100644 --- a/ddprof-lib/src/test/cpp/wallClockCounters_ut.cpp +++ b/ddprof-lib/src/test/cpp/wallClockCounters_ut.cpp @@ -18,25 +18,25 @@ class WallClockCountersTest : public ::testing::Test { } }; -TEST_F(WallClockCountersTest, DrainReturnsAndClearsSuppressedSampledRun) { - WallClockCounters::incrementSuppressedSampledRun(); - WallClockCounters::incrementSuppressedSampledRun(); +TEST_F(WallClockCountersTest, DrainReturnsAndClearsSuppressedOwnedBlock) { + WallClockCounters::incrementSuppressedOwnedBlock(); + WallClockCounters::incrementSuppressedOwnedBlock(); - EXPECT_EQ(2ULL, WallClockCounters::drainSuppressedSampledRun()); - EXPECT_EQ(0ULL, WallClockCounters::drainSuppressedSampledRun()); + EXPECT_EQ(2ULL, WallClockCounters::drainSuppressedOwnedBlock()); + EXPECT_EQ(0ULL, WallClockCounters::drainSuppressedOwnedBlock()); } -TEST_F(WallClockCountersTest, ResetClearsPendingSuppressedSampledRun) { - WallClockCounters::incrementSuppressedSampledRun(); +TEST_F(WallClockCountersTest, ResetClearsPendingSuppressedOwnedBlock) { + WallClockCounters::incrementSuppressedOwnedBlock(); WallClockCounters::reset(); - EXPECT_EQ(0ULL, WallClockCounters::drainSuppressedSampledRun()); + EXPECT_EQ(0ULL, WallClockCounters::drainSuppressedOwnedBlock()); } TEST_F(WallClockCountersTest, ResetIsIdempotent) { WallClockCounters::reset(); WallClockCounters::reset(); - EXPECT_EQ(0ULL, WallClockCounters::drainSuppressedSampledRun()); + EXPECT_EQ(0ULL, WallClockCounters::drainSuppressedOwnedBlock()); } diff --git a/ddprof-lib/src/test/fuzz/fuzz_threadFilter.cpp b/ddprof-lib/src/test/fuzz/fuzz_threadFilter.cpp index 37dc9edc8c..fda73bb89d 100644 --- a/ddprof-lib/src/test/fuzz/fuzz_threadFilter.cpp +++ b/ddprof-lib/src/test/fuzz/fuzz_threadFilter.cpp @@ -35,7 +35,7 @@ * I2. lookupByTid(tid) retains every live owner's identity. activeSlotForId() * is non-null exactly when its owner has registered in the current epoch. * I3. Restart makes old block state ineligible for suppression; registering - * a retained owner clears its block state and sampled-this-run marker. + * a retained owner clears its block state and sampled block generation. * I4. A generation-checked exitBlockedRun() called with a generation other * than the block run's current one must return false and must not * change that slot's active-block-state (a stale/forged token must @@ -111,7 +111,7 @@ extern "C" int LLVMFuzzerTestOneInput(const uint8_t* data, size_t size) { auto* block = g_tracker->slotForId(slot_id); if (block->activeBlockState() != OSThreadState::UNKNOWN || block->activeBlockOwner() != BlockRunOwner::NONE || - block->sampledThisRun()) { + block->sampledBlockGeneration() != 0) { // Newly registered or refreshed owners start with clean payload (I3). __builtin_trap(); } @@ -142,7 +142,8 @@ extern "C" int LLVMFuzzerTestOneInput(const uint8_t* data, size_t size) { u64 token = g_tracker->enterBlockedRun(g_filter, it->second, state); if (token != 0) { g_last_token[it->second] = token; - g_tracker->slotForId(it->second)->markSampledThisRun(state); + g_tracker->slotForId(it->second)->markBlockGenerationSampled( + WallClockBlockTracker::tokenGeneration(token)); } } } else if (op < 0xB0) { @@ -151,9 +152,9 @@ extern "C" int LLVMFuzzerTestOneInput(const uint8_t* data, size_t size) { auto tok_it = g_last_token.find(it->second); if (tok_it != g_last_token.end()) { uint8_t corruption_byte = nextByte(); - u32 correct_generation = WallClockBlockTracker::tokenGeneration(tok_it->second); + u64 correct_generation = WallClockBlockTracker::tokenGeneration(tok_it->second); bool corrupt = (corruption_byte & 0x1) != 0; - u32 generation = corrupt + u64 generation = corrupt ? correct_generation + 1 + (corruption_byte >> 1) : correct_generation; @@ -193,7 +194,7 @@ extern "C" int LLVMFuzzerTestOneInput(const uint8_t* data, size_t size) { auto* identity = g_filter->slotForId(kv.second); ThreadEntry stale{kv.first, identity, kv.second, identity->lifecycleGeneration(), identity->recordingEpoch()}; - if (g_tracker->shouldSuppressOwnedBlock(g_filter, stale)) { + if (g_tracker->isOwnedBlockSuppressionCandidate(g_filter, stale)) { // Retained payload from the previous epoch cannot suppress a sample (I3). __builtin_trap(); } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java index 6ce81762cc..06da945600 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java @@ -15,15 +15,23 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; public class JavaProfilerApiSurfaceTest { @Test - public void ownedBlockHooksAreNotPublicApiBeforeTaskBlockInstrumentation() throws Exception { - assertNotPublic(JavaProfiler.class.getDeclaredMethod("parkEnter")); + public void taskBlockApiIsPublicButInternalHooksRemainPackageScoped() throws Exception { + Method parkEnter = JavaProfiler.class.getDeclaredMethod("parkEnter"); + assertNotPublic(parkEnter); + assertEquals(boolean.class, parkEnter.getReturnType()); assertNotPublic(JavaProfiler.class.getDeclaredMethod( "parkExit", long.class, long.class)); assertNotPublic(JavaProfiler.class.getDeclaredMethod("blockEnter", int.class)); assertNotPublic(JavaProfiler.class.getDeclaredMethod("blockExit", long.class)); + assertTrue(Modifier.isPublic(JavaProfiler.class + .getDeclaredMethod("beginTaskBlock").getModifiers())); + assertTrue(Modifier.isPublic(JavaProfiler.class + .getDeclaredMethod("endTaskBlock", long.class, long.class, long.class) + .getModifiers())); } // State-mutating hooks into the process-wide profiler singleton: reachable from tests only @@ -57,6 +65,6 @@ public void referenceChainTestSeamsAreNotPublicApi() { private static void assertNotPublic(Method method) { assertFalse(Modifier.isPublic(method.getModifiers()), - method.getName() + " must remain non-public until PR2 wires TaskBlock instrumentation"); + method.getName() + " is an internal instrumentation hook"); } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/ProfilerOwnedBlockHooks.java b/ddprof-test/src/test/java/com/datadoghq/profiler/ProfilerOwnedBlockHooks.java index f58837f5de..68208fac73 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/ProfilerOwnedBlockHooks.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/ProfilerOwnedBlockHooks.java @@ -9,8 +9,8 @@ public final class ProfilerOwnedBlockHooks { private ProfilerOwnedBlockHooks() {} - public static void parkEnter(JavaProfiler profiler) { - profiler.parkEnter(); + public static boolean parkEnter(JavaProfiler profiler) { + return profiler.parkEnter(); } public static void parkExit(JavaProfiler profiler, long blocker, long unblockingSpanId) { @@ -24,4 +24,13 @@ public static long blockEnter(JavaProfiler profiler, int state) { public static void blockExit(JavaProfiler profiler, long token) { profiler.blockExit(token); } + + public static long beginTaskBlockForThread(JavaProfiler profiler, Thread thread) { + return profiler.beginTaskBlockForThread(thread); + } + + public static boolean endTaskBlockForThread(JavaProfiler profiler, Thread thread, long token, + long blocker, long unblockingSpanId) { + return profiler.endTaskBlockForThread(thread, token, blocker, unblockingSpanId); + } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ConcurrentOwnedBlockChurnTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ConcurrentOwnedBlockChurnTest.java index 55b8eeff24..f6ec5aeecc 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ConcurrentOwnedBlockChurnTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/ConcurrentOwnedBlockChurnTest.java @@ -42,7 +42,7 @@ public class ConcurrentOwnedBlockChurnTest extends AbstractProfilerTest { private static final long BLOCK_MILLIS = 250; private static final int WORKERS_PER_ROUND = 24; private static final int ROUNDS = 8; - private static final String SUPPRESSED_RUN_COUNTER = "wc_signals_suppressed_sampled_run"; + private static final String SUPPRESSED_OWNED_BLOCK_COUNTER = "wc_signals_suppressed_owned_block"; private static final String WORKER_NAME_PREFIX = "owned-block-churn-"; @@ -196,6 +196,6 @@ private Map countOwnedBlockSamples() { } private long suppressedSignals() { - return profiler.getDebugCounters().getOrDefault(SUPPRESSED_RUN_COUNTER, -1L); + return profiler.getDebugCounters().getOrDefault(SUPPRESSED_OWNED_BLOCK_COUNTER, -1L); } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockApiTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockApiTest.java new file mode 100644 index 0000000000..f91a0f79cd --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockApiTest.java @@ -0,0 +1,279 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import java.nio.file.Files; +import java.nio.file.Path; +import java.lang.reflect.Method; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; +import java.util.concurrent.atomic.AtomicReference; +import org.junit.jupiter.api.Assumptions; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.ValueSource; +import com.datadoghq.profiler.JfrEvents; +import com.datadoghq.profiler.ProfilerOwnedBlockHooks; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** End-to-end coverage for the paired synchronous TaskBlock API. */ +public class JavaProfilerTaskBlockApiTest extends AbstractProfilerTest { + private static final long BLOCKER = 0x7301L; + private static final long UNBLOCKING_SPAN_ID = 0x7302L; + + @Test + public void pairedApiEmitsTaskBlockWithStack() throws Exception { + assertTrue(runEligibleBlock(BLOCKER)); + stopProfiler(); + + JfrEvents events = verifyEvents("datadog.TaskBlock"); + TaskBlockAssertions.assertNoAnchorFields(events); + TaskBlockAssertions.assertContainsStackTrace(events); + TaskBlockAssertions.assertContainsJavaType(events, "JavaProfilerTaskBlockApiTest"); + TaskBlockAssertions.assertNoCorrelationId(events); + TaskBlockAssertions.assertContains(events, 0L, 0L, BLOCKER, UNBLOCKING_SPAN_ID); + TaskBlockAssertions.assertContainsObservedState(events, "SLEEPING"); + } + + @ParameterizedTest + @ValueSource(strings = {"start", "resume"}) + public void rejectedDuplicateStartOrResumePreservesActiveTaskBlockRecording(String action) + throws Exception { + IllegalStateException rejected = assertThrows( + IllegalStateException.class, + () -> profiler.execute(action + "," + getProfilerCommand())); + assertEquals("Profiler already started", rejected.getMessage()); + + assertTrue(runEligibleBlock(BLOCKER)); + stopProfiler(); + + TaskBlockAssertions.assertContains( + verifyEvents("datadog.TaskBlock"), 0L, 0L, BLOCKER, UNBLOCKING_SPAN_ID); + } + + @Test + public void invalidAndNestedTokensDoNotLoseCurrentOwner() throws Exception { + AtomicBoolean recorded = new AtomicBoolean(); + runWorker(() -> { + long token = profiler.beginTaskBlock(); + assertTrue(token != 0); + assertEquals(0L, profiler.beginTaskBlock()); + assertFalse(profiler.endTaskBlock(token + 1, BLOCKER, UNBLOCKING_SPAN_ID)); + Thread.sleep(200L); + recorded.set(profiler.endTaskBlock(token, BLOCKER, UNBLOCKING_SPAN_ID)); + }); + assertTrue(recorded.get()); + } + + @Test + public void tooShortIntervalStillClearsLifecycle() throws Exception { + AtomicBoolean recorded = new AtomicBoolean(true); + AtomicLong secondToken = new AtomicLong(); + runWorker(() -> { + long token = profiler.beginTaskBlock(); + recorded.set(profiler.endTaskBlock(token, BLOCKER, UNBLOCKING_SPAN_ID)); + secondToken.set(profiler.beginTaskBlock()); + profiler.endTaskBlock(secondToken.get(), BLOCKER, UNBLOCKING_SPAN_ID); + }); + + assertFalse(recorded.get()); + assertTrue(secondToken.get() != 0); + stopProfiler(); + assertTrue(getRecordedCounterValue("task_block_skipped_too_short") > 0); + } + + @Test + public void contextWindowAdmissionAndCrossingAreEnforced() throws Exception { + AtomicLong tokenAfterWindow = new AtomicLong(); + runWorker(() -> { + profiler.addThread(); + try { + assertEquals(0L, profiler.beginTaskBlock()); + } finally { + profiler.removeThread(); + } + + long crossedToken = profiler.beginTaskBlock(); + assertTrue(crossedToken != 0); + profiler.addThread(); + profiler.removeThread(); + Thread.sleep(20L); + assertFalse(profiler.endTaskBlock( + crossedToken, BLOCKER, UNBLOCKING_SPAN_ID)); + + tokenAfterWindow.set(profiler.beginTaskBlock()); + profiler.endTaskBlock(tokenAfterWindow.get(), BLOCKER, UNBLOCKING_SPAN_ID); + }); + assertTrue(tokenAfterWindow.get() != 0, + "context rejection must still clear the prior lifecycle"); + + stopProfiler(); + assertTrue(getRecordedCounterValue("task_block_skipped_context_window") > 0, + "context-window crossing must be counted separately from trace-context rejection"); + assertEquals(0L, getRecordedCounterValue("task_block_skipped_trace_context"), + "context-window crossing must not be attributed to the trace-context counter"); + } + + @Test + public void traceContextRejectsAtEntry() throws Exception { + AtomicLong token = new AtomicLong(-1L); + runWorker(() -> { + profiler.setTraceContext(0x5100L, 0x5101L, 0L, 0x5101L, -1, null, -1, null); + try { + token.set(profiler.beginTaskBlock()); + } finally { + profiler.clearTraceContext(); + } + }); + assertEquals(0L, token.get(), + "a traced interval must not arm timer-side suppression"); + } + + @Test + public void mismatchedThreadIsRejectedAtBeginAndEnd() throws Exception { + AtomicLong beginToken = new AtomicLong(-1L); + AtomicBoolean endResult = new AtomicBoolean(true); + AtomicLong ownToken = new AtomicLong(); + Thread other = new Thread(() -> { }, "taskblock-mismatch-other"); + + runWorker(() -> { + beginToken.set(ProfilerOwnedBlockHooks.beginTaskBlockForThread(profiler, other)); + + ownToken.set(profiler.beginTaskBlock()); + assertTrue(ownToken.get() != 0); + endResult.set(ProfilerOwnedBlockHooks.endTaskBlockForThread( + profiler, other, ownToken.get(), BLOCKER, UNBLOCKING_SPAN_ID)); + profiler.endTaskBlock(ownToken.get(), BLOCKER, UNBLOCKING_SPAN_ID); + }); + + assertEquals(0L, beginToken.get(), + "beginTaskBlock0 must reject a jthread that does not identify the calling thread"); + assertFalse(endResult.get(), + "endTaskBlock0 must reject a jthread that does not identify the calling thread"); + + stopProfiler(); + assertTrue(getRecordedCounterValue("task_block_skipped_thread_mismatch") > 0); + } + + @Test + public void virtualThreadCannotMutateCarrierTaskBlockState() throws Exception { + Method startVirtualThread; + try { + startVirtualThread = + Thread.class.getMethod("startVirtualThread", Runnable.class); + } catch (NoSuchMethodException unavailableBeforeJdk21) { + Assumptions.assumeTrue(false, "virtual threads require JDK 21"); + return; + } + + AtomicLong token = new AtomicLong(-1L); + Thread virtual = (Thread) startVirtualThread.invoke(null, (Runnable) () -> + token.set(profiler.beginTaskBlock())); + virtual.join(5_000L); + assertFalse(virtual.isAlive()); + assertEquals(0L, token.get()); + + AtomicLong platformToken = new AtomicLong(); + runWorker(() -> { + platformToken.set(profiler.beginTaskBlock()); + profiler.endTaskBlock(platformToken.get(), BLOCKER, UNBLOCKING_SPAN_ID); + }); + assertTrue(platformToken.get() != 0, + "virtual-thread rejection must not strand carrier ownership"); + } + + @Test + public void liveDumpPreservesTaskBlockAfterEntrySample() throws Exception { + CountDownLatch armed = new CountDownLatch(1); + CountDownLatch release = new CountDownLatch(1); + AtomicBoolean recorded = new AtomicBoolean(); + AtomicReference error = new AtomicReference<>(); + long before = profiler.getDebugCounters() + .getOrDefault("wc_signals_suppressed_owned_block", 0L); + Thread worker = new Thread(() -> { + try { + long token = profiler.beginTaskBlock(); + assertTrue(token != 0); + armed.countDown(); + assertTrue(release.await(5, TimeUnit.SECONDS)); + recorded.set(profiler.endTaskBlock(token, BLOCKER, UNBLOCKING_SPAN_ID)); + } catch (Throwable t) { + error.set(t); + } + }, "taskblock-live-dump"); + + worker.start(); + assertTrue(armed.await(5, TimeUnit.SECONDS)); + waitForCounterAbove("wc_signals_suppressed_owned_block", before, 5_000L); + Path snapshot = Files.createTempFile("taskblock-live-dump-", ".jfr"); + try { + dump(snapshot); + } finally { + Files.deleteIfExists(snapshot); + } + release.countDown(); + worker.join(5_000L); + assertFalse(worker.isAlive()); + if (error.get() != null) throw new AssertionError(error.get()); + assertTrue(recorded.get()); + + stopProfiler(); + TaskBlockAssertions.assertContainsStackTrace(verifyEvents("datadog.TaskBlock")); + } + + @Override + protected String getProfilerCommand() { + return "wall=1ms,filter=,wallprecheck=true"; + } + + private boolean runEligibleBlock(long blocker) throws Exception { + AtomicBoolean result = new AtomicBoolean(); + runWorker(() -> { + long token = profiler.beginTaskBlock(); + if (token == 0) throw new AssertionError("interval was not armed"); + Thread.sleep(200L); + result.set(profiler.endTaskBlock(token, blocker, UNBLOCKING_SPAN_ID)); + }); + return result.get(); + } + + private void runWorker(ThrowingRunnable action) throws Exception { + AtomicReference error = new AtomicReference<>(); + Thread worker = new Thread(() -> { + try { + action.run(); + } catch (Throwable t) { + error.set(t); + } + }, "taskblock-paired-api"); + worker.start(); + worker.join(5_000L); + assertFalse(worker.isAlive()); + if (error.get() != null) throw new AssertionError(error.get()); + } + + private void waitForCounterAbove(String name, long baseline, long timeoutMillis) + throws Exception { + long deadline = System.nanoTime() + TimeUnit.MILLISECONDS.toNanos(timeoutMillis); + while (System.nanoTime() < deadline) { + if (profiler.getDebugCounters().getOrDefault(name, 0L) > baseline) return; + Thread.sleep(10L); + } + throw new AssertionError("Counter did not increase: " + name); + } + + @FunctionalInterface + private interface ThrowingRunnable { + void run() throws Exception; + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockDisabledTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockDisabledTest.java new file mode 100644 index 0000000000..2a04c8fdf4 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockDisabledTest.java @@ -0,0 +1,24 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import org.junit.jupiter.api.Test; + +import static org.junit.jupiter.api.Assertions.assertEquals; + +/** Verifies that TaskBlock does not change legacy/context wall-clock scope. */ +public class JavaProfilerTaskBlockDisabledTest extends AbstractProfilerTest { + @Test + public void pairedApiIsInactiveOutsideAllThreadScope() { + assertEquals(0L, profiler.beginTaskBlock()); + } + + @Override + protected String getProfilerCommand() { + return "wall=1ms,filter=0,wallprecheck=true"; + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockLightweightTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockLightweightTest.java new file mode 100644 index 0000000000..3654a90a34 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockLightweightTest.java @@ -0,0 +1,85 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicReference; +import org.junit.jupiter.api.Test; +import com.datadoghq.profiler.JfrEvents; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** End-to-end coverage for stackless TaskBlock events in lightweight mode. */ +public class JavaProfilerTaskBlockLightweightTest extends AbstractProfilerTest { + private static final long BLOCKER = 0x7401L; + private static final long UNBLOCKING_SPAN_ID = 0x7402L; + + @Test + public void suppressedWallSamplesAreReplacedByAStacklessTaskBlock() throws Exception { + CountDownLatch armed = new CountDownLatch(1); + CountDownLatch release = new CountDownLatch(1); + AtomicBoolean recorded = new AtomicBoolean(); + AtomicReference error = new AtomicReference<>(); + long suppressedBefore = profiler.getDebugCounters() + .getOrDefault("wc_signals_suppressed_owned_block", 0L); + Thread worker = new Thread(() -> { + try { + long token = profiler.beginTaskBlock(); + assertTrue(token != 0, "Expected TaskBlock interval to be armed"); + armed.countDown(); + assertTrue(release.await(5, TimeUnit.SECONDS)); + recorded.set(profiler.endTaskBlock(token, BLOCKER, UNBLOCKING_SPAN_ID)); + } catch (Throwable t) { + error.set(t); + } + }, "taskblock-lightweight"); + + worker.start(); + assertTrue(armed.await(5, TimeUnit.SECONDS)); + waitForCounterAbove( + "wc_signals_suppressed_owned_block", suppressedBefore, 5_000L); + // The periodic signal may arrive less than 1 ms after beginTaskBlock(). + Thread.sleep(10L); + release.countDown(); + worker.join(5_000L); + assertFalse(worker.isAlive()); + if (error.get() != null) throw new AssertionError(error.get()); + assertTrue(recorded.get(), "Expected stackless TaskBlock event to be recorded"); + + stopProfiler(); + JfrEvents events = verifyEvents("datadog.TaskBlock"); + assertEquals(1L, events.count()); + TaskBlockAssertions.assertContainsNoStackTrace(events); + TaskBlockAssertions.assertNoAnchorFields(events); + TaskBlockAssertions.assertNoCorrelationId(events); + TaskBlockAssertions.assertContains(events, 0L, 0L, BLOCKER, UNBLOCKING_SPAN_ID); + TaskBlockAssertions.assertContainsObservedState(events, "SLEEPING"); + assertTrue(getRecordedCounterValue("wc_signals_suppressed_owned_block") + > suppressedBefore); + assertEquals(1L, getRecordedCounterValue("task_block_emitted")); + assertEquals(0L, getRecordedCounterValue("task_block_stack_capture_failed")); + } + + private void waitForCounterAbove(String name, long baseline, long timeoutMillis) + throws Exception { + long deadline = System.nanoTime() + TimeUnit.MILLISECONDS.toNanos(timeoutMillis); + while (System.nanoTime() < deadline) { + if (profiler.getDebugCounters().getOrDefault(name, 0L) > baseline) return; + Thread.sleep(10L); + } + throw new AssertionError("Counter did not increase: " + name); + } + + @Override + protected String getProfilerCommand() { + return "wall=1ms,filter=,wallprecheck=true,lightweight=yes"; + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockPreExistingThreadTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockPreExistingThreadTest.java new file mode 100644 index 0000000000..bb21a3bee8 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockPreExistingThreadTest.java @@ -0,0 +1,76 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.Future; +import java.util.concurrent.TimeUnit; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; +import com.datadoghq.profiler.JfrEvents; + +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** Verifies TaskBlock TLS initialization for threads created before profiler startup. */ +public class JavaProfilerTaskBlockPreExistingThreadTest extends AbstractProfilerTest { + private static final long BLOCKER = 0x7401L; + private static final long UNBLOCKING_SPAN_ID = 0x7402L; + + private ExecutorService preExistingWorker; + private Thread preExistingThread; + + @Override + protected void beforeProfilerStart() throws Exception { + preExistingWorker = + Executors.newSingleThreadExecutor( + task -> { + Thread worker = new Thread(task, "taskblock-pre-existing"); + worker.setDaemon(true); + return worker; + }); + preExistingThread = preExistingWorker.submit(Thread::currentThread).get(); + } + + /** Stops the worker that was deliberately created before profiler startup. */ + @AfterEach + public void stopPreExistingWorker() throws InterruptedException { + if (preExistingWorker == null) return; + preExistingWorker.shutdownNow(); + assertTrue( + preExistingWorker.awaitTermination(5, TimeUnit.SECONDS), + "Pre-existing TaskBlock worker did not terminate"); + } + + /** Verifies that the first post-start TaskBlock call initializes carrier-local TLS. */ + @Test + public void preExistingThreadCanRecordTaskBlockAfterProfilerStart() throws Exception { + Future recorded = + preExistingWorker.submit( + () -> { + assertSame(preExistingThread, Thread.currentThread()); + long token = profiler.beginTaskBlock(); + assertTrue(token != 0, "Pre-existing thread must initialize TaskBlock TLS"); + Thread.sleep(200L); + return profiler.endTaskBlock(token, BLOCKER, UNBLOCKING_SPAN_ID); + }); + + assertTrue(recorded.get(5, TimeUnit.SECONDS)); + stopProfiler(); + + JfrEvents events = verifyEvents("datadog.TaskBlock"); + TaskBlockAssertions.assertContainsStackTrace(events); + TaskBlockAssertions.assertContains( + events, 0L, 0L, BLOCKER, UNBLOCKING_SPAN_ID); + } + + @Override + protected String getProfilerCommand() { + return "wall=1ms,filter=,wallprecheck=true"; + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java index c8f6a501e7..07ae6de492 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java @@ -54,11 +54,11 @@ protected void withTestAssumptions() { @Override protected String getProfilerCommand() { - return "wall=1ms,wallprecheck=true,jvmtistacks=true"; + return "wall=1ms,filter=,wallprecheck=true,jvmtistacks=true"; } @Override protected String getPrecheckDisabledProfilerCommand() { - return "wall=1ms,wallprecheck=false,jvmtistacks=true"; + return "wall=1ms,filter=,wallprecheck=false,jvmtistacks=true"; } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckEfficiencyTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckEfficiencyTest.java index 0f150fb773..52274cf155 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckEfficiencyTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckEfficiencyTest.java @@ -24,9 +24,9 @@ /** * Measures the theoretical upper bound on {@code SIGVTALRM} suppression by running with - * {@code wallprecheck=false} and classifying sample states. The once-per-run filter + * {@code wallprecheck=false} and classifying sample states. Lifecycle ownership * ({@code wallprecheck=true}) suppresses {@code SLEEPING}, {@code CONDVAR_WAIT}, and - * {@code OBJECT_WAIT} after the entry sample; {@code RUNNABLE} is not skipped. Monitor + * suppresses {@code OBJECT_WAIT}; {@code RUNNABLE} is not skipped. Monitor * contention ({@code MONITOR_WAIT}) is also suppressible when monitor hooks identify the blocked * interval. */ @@ -45,23 +45,20 @@ public void compareSuppressionRates() throws Exception { AtomicBoolean stop = new AtomicBoolean(false); Object monitor = new Object(); - // SLEEPING / CONDVAR_WAIT — suppressed by once-per-run filter + // SLEEPING / CONDVAR_WAIT — suppressible with lifecycle ownership Thread sleeping = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); ready.countDown(); try { Thread.sleep(10_000); } catch (InterruptedException ignored) {} }, EFFICIENCY_SLEEPING); - // CONDVAR_WAIT — suppressed by once-per-run filter + // CONDVAR_WAIT — suppressible with lifecycle ownership Thread parked = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); ready.countDown(); LockSupport.parkNanos(10_000_000_000L); }, EFFICIENCY_PARKED); - // OBJECT_WAIT — suppressed by the once-per-run filter. + // OBJECT_WAIT — suppressible with lifecycle ownership. Thread waiting = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); ready.countDown(); synchronized (monitor) { try { monitor.wait(10_000); } catch (InterruptedException ignored) {} @@ -70,7 +67,6 @@ public void compareSuppressionRates() throws Exception { // RUNNABLE — not skipped Thread working = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); ready.countDown(); long x = 0; while (!stop.get()) { x++; } @@ -196,10 +192,7 @@ public void realisticServiceWorkload() throws Exception { AtomicInteger threadIndex = new AtomicInteger(0); ExecutorService pool = Executors.newFixedThreadPool(POOL_SIZE, r -> { - Thread t = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); - r.run(); - }); + Thread t = new Thread(r); t.setName("realistic-pool-" + threadIndex.incrementAndGet()); t.setDaemon(true); return t; @@ -213,7 +206,6 @@ public void realisticServiceWorkload() throws Exception { Thread.sleep(50); Thread scheduler = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); while (!stop.get()) { try { Thread.sleep(SCHEDULE_INTERVAL_MS); @@ -232,7 +224,6 @@ public void realisticServiceWorkload() throws Exception { scheduler.start(); Thread hotThread = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); long x = 0; while (!stop.get()) { x++; } }, "realistic-hot"); @@ -254,6 +245,12 @@ public void realisticServiceWorkload() throws Exception { long sleepSamples = 0, parkSamples = 0, otherSamples = 0; for (JfrEvent item : events) { + String threadName = item.getThreadName("eventThread"); + if (threadName == null || (!threadName.startsWith("realistic-pool-") + && !"realistic-scheduler".equals(threadName) + && !"realistic-hot".equals(threadName))) { + continue; + } String stack = item.getStackTraceString(); if (stack == null) { otherSamples++; @@ -296,9 +293,11 @@ public void realisticServiceWorkload() throws Exception { @Override protected String getProfilerCommand() { - // The workload deliberately has no tracing context; it relies on the - // default context-filter scope (filter="0") plus each worker thread - // explicitly registering itself via registerCurrentThreadForWallClockProfiling(). - return "wall=1ms"; + // The workload deliberately has no tracing context, and owned-block + // suppression only applies to the unfiltered wall-clock scope, so + // keep unfiltered wall-clock sampling enabled explicitly plus each + // worker thread explicitly registering itself via + // registerCurrentThreadForWallClockProfiling(). + return "wall=1ms,filter="; } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java index 8f5133bea0..c109a50d23 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java @@ -22,8 +22,8 @@ import static org.junit.jupiter.api.Assertions.assertTrue; /** - * Verifies once-per-run signal suppression ({@code wallprecheck=true}): a sleeping thread - * should produce a handful of {@code MethodSample} events (entry + boundary jitter), not ~300. + * Verifies lifecycle-owned signal suppression ({@code wallprecheck=true}): a sleeping thread + * should produce at most boundary-race {@code MethodSample} events, not ~300. * Requires JDK 11+ — JDK 8 HotSpot reports inconsistent OSThread states for sleep. */ public class PrecheckTest extends AbstractProfilerTest { @@ -41,7 +41,6 @@ public void testSleepingThreadIsNotSampled() throws InterruptedException { Assumptions.assumeTrue(!Platform.isJ9()); Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); leaveClearedInitializedContext(); - registerCurrentThreadForWallClockProfiling(); long token = ProfilerOwnedBlockHooks.blockEnter(profiler, OSTHREAD_STATE_SLEEPING); assertTrue(token != 0, "Expected native blockEnter to arm SLEEPING state"); @@ -53,25 +52,38 @@ public void testSleepingThreadIsNotSampled() throws InterruptedException { stopProfiler(); - long sampleCount = verifyEvents("datadog.MethodSample", false) - .count(); - // Explicitly owned once-per-run filter: entry signal emits, subsequent signals are - // suppressed until blockExit clears the owned run. + long sampleCount = samplesForThread(Thread.currentThread().getName()); + // Lifecycle ownership suppresses deliberate signals from blockEnter until blockExit. + // A few boundary-race samples remain possible. assertTrue(sampleCount < 10, "Expected nearly no MethodSample events for a sleeping thread with wallprecheck=true, got: " + sampleCount); Map counters = profiler.getDebugCounters(); - if (counters.containsKey("wc_signals_suppressed_sampled_run")) { - assertTrue(counters.get("wc_signals_suppressed_sampled_run") > 0, - "wc_signals_suppressed_sampled_run should be > 0 for a 300 ms Thread.sleep()"); + if (counters.containsKey("wc_signals_suppressed_owned_block")) { + assertTrue(counters.get("wc_signals_suppressed_owned_block") > 0, + "wc_signals_suppressed_owned_block should be > 0 for a 300 ms Thread.sleep()"); + } + } + + @Test + public void testBlockEnterRejectedWithActiveTraceContext() { + Assumptions.assumeTrue(!Platform.isJ9()); + Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); + + profiler.setTraceContext(0x5100L, 0x5101L, 0L, 0x5101L, -1, null, -1, null); + try { + long token = ProfilerOwnedBlockHooks.blockEnter(profiler, OSTHREAD_STATE_SLEEPING); + assertEquals(0L, token, + "Expected blockEnter to reject arming while an active trace context is set"); + } finally { + profiler.clearTraceContext(); } } /** * Verifies that {@code samplePoolSize} in {@code datadog.WallClockSamplingEpoch} still counts - * threads whose owned blocked run is already suppressed. The timer drops those threads before - * reservoir sampling, but the pool size must be taken before that step so it keeps counting - * every candidate, as it does in unfiltered recordings. + * threads whose owned blocked run is already suppressed. The pool size is taken before the + * timer rejects those threads, so it keeps counting every candidate. * * @throws InterruptedException if a worker is interrupted */ @@ -85,14 +97,12 @@ public void samplePoolSizeCountsSuppressedThreads() throws InterruptedException Thread[] workers = new Thread[POOL_WORKERS]; for (int i = 0; i < POOL_WORKERS; i++) { workers[i] = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); long token = ProfilerOwnedBlockHooks.blockEnter(profiler, OSTHREAD_STATE_SLEEPING); try { Thread.sleep(POOL_SLEEP_MILLIS); } catch (InterruptedException ignored) { } finally { ProfilerOwnedBlockHooks.blockExit(profiler, token); - profiler.removeThread(); } }, "precheck-pool-" + i); workers[i].start(); @@ -107,7 +117,7 @@ public void samplePoolSizeCountsSuppressedThreads() throws InterruptedException // Before the fix those ticks reported a pool size of 0. boolean sawFullPoolWhileSuppressing = false; for (JfrEvent epoch : verifyEvents("datadog.WallClockSamplingEpoch")) { - if (epoch.getLong("numSuppressedSampledRun", 0) >= POOL_WORKERS + if (epoch.getLong("numSuppressedOwnedBlock", 0) >= POOL_WORKERS && epoch.getLong("samplePoolSize", 0) >= POOL_WORKERS) { sawFullPoolWhileSuppressing = true; break; @@ -123,16 +133,19 @@ public void unownedSleepingThreadIsNotExactOncePerRunSuppressed() throws Excepti Assumptions.assumeTrue(!Platform.isJ9()); Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); leaveClearedInitializedContext(); - registerCurrentThreadForWallClockProfiling(); Thread.sleep(300); stopProfiler(); - long sampleCount = verifyEvents("datadog.MethodSample", false) - .count(); - assertTrue(sampleCount >= 10, - "Unowned Thread.sleep must not be exact once-per-run suppressed; got: " + sampleCount); + long sampleCount = samplesForThread(Thread.currentThread().getName()); + assertTrue(sampleCount > 0, + "Unowned Thread.sleep must remain sampled; got: " + sampleCount); + Map counters = profiler.getDebugCounters(); + assertTrue(counters.getOrDefault("wc_unowned_blocked_recorded", 0L) > 0, + "Expected the weighted unowned-block fallback to record samples"); + assertTrue(counters.getOrDefault("wc_unowned_blocked_suppressed", 0L) > 0, + "Expected the weighted unowned-block fallback to suppress intermediate samples"); } @Test @@ -141,7 +154,6 @@ public void unownedSleepingTailWeightIsPreserved() throws Exception { Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); Thread sleeper = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); try { for (int i = 0; i < TAIL_WEIGHT_ITERATIONS; i++) { Thread.sleep(TAIL_WEIGHT_SLEEP_MILLIS); @@ -163,19 +175,19 @@ public void unownedSleepingTailWeightIsPreserved() throws Exception { WeightedSamples weightedSamples = weightedSamplesForThread(TAIL_WEIGHT_THREAD); assertTrue(weightedSamples.count > 0, "Expected MethodSample events for " + TAIL_WEIGHT_THREAD); - long expectedTailContribution = TAIL_WEIGHT_ITERATIONS; - assertTrue(weightedSamples.weight >= weightedSamples.count + expectedTailContribution, + assertTrue(weightedSamples.weight > weightedSamples.count, "Expected preserved suppressed tail weight for " + TAIL_WEIGHT_THREAD + ", count=" + weightedSamples.count - + ", weight=" + weightedSamples.weight - + ", expectedTailContribution=" + expectedTailContribution); + + ", weight=" + weightedSamples.weight); + assertTrue(profiler.getDebugCounters() + .getOrDefault("wc_unowned_blocked_suppressed", 0L) > 0, + "Expected unowned blocked samples to be suppressed and represented by weight"); } @Test public void tracedSleepingThreadIsSampled() throws InterruptedException { Assumptions.assumeTrue(!Platform.isJ9()); Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); - registerCurrentThreadForWallClockProfiling(); Map countersBefore = profiler.getDebugCounters(); profiler.setTraceContext(0x5100L, 0x5101L, 0L, 0x5101L, -1, null, -1, null); @@ -187,17 +199,16 @@ public void tracedSleepingThreadIsSampled() throws InterruptedException { stopProfiler(); - long sampleCount = verifyEvents("datadog.MethodSample", false) - .count(); + long sampleCount = samplesForThread(Thread.currentThread().getName()); assertTrue(sampleCount >= 10, "Expected normal MethodSample volume for traced sleep, got: " + sampleCount); - if (countersBefore.containsKey("wc_signals_suppressed_sampled_run")) { - long suppressedBefore = countersBefore.get("wc_signals_suppressed_sampled_run"); + if (countersBefore.containsKey("wc_signals_suppressed_owned_block")) { + long suppressedBefore = countersBefore.get("wc_signals_suppressed_owned_block"); long suppressedAfter = profiler.getDebugCounters() - .getOrDefault("wc_signals_suppressed_sampled_run", 0L); + .getOrDefault("wc_signals_suppressed_owned_block", 0L); assertEquals(suppressedBefore, suppressedAfter, - "wc_signals_suppressed_sampled_run must not increment for traced sleep"); + "wc_signals_suppressed_owned_block must not increment for traced sleep"); } } @@ -205,16 +216,15 @@ public void tracedSleepingThreadIsSampled() throws InterruptedException { public void suppressionCounterIsZeroWhenPrecheckDisabled() throws Exception { Assumptions.assumeTrue(!Platform.isJ9()); Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); - registerCurrentThreadForWallClockProfiling(); // Stop the wallprecheck=true recording started by @BeforeEach before starting a new one. stopProfiler(); Map before = profiler.getDebugCounters(); - if (!before.containsKey("wc_signals_suppressed_sampled_run")) { + if (!before.containsKey("wc_signals_suppressed_owned_block")) { return; // counter not available in this build } - long suppressedBefore = before.get("wc_signals_suppressed_sampled_run"); + long suppressedBefore = before.get("wc_signals_suppressed_owned_block"); Path recordingB = Files.createTempFile(Paths.get("/tmp/recordings"), "PrecheckTest_disabled_", ".jfr"); @@ -224,11 +234,11 @@ public void suppressionCounterIsZeroWhenPrecheckDisabled() throws Exception { profiler.stop(); long suppressedAfter = profiler.getDebugCounters() - .getOrDefault("wc_signals_suppressed_sampled_run", 0L); + .getOrDefault("wc_signals_suppressed_owned_block", 0L); Files.deleteIfExists(recordingB); assertEquals(suppressedBefore, suppressedAfter, - "wc_signals_suppressed_sampled_run must not increment when wallprecheck=false"); + "wc_signals_suppressed_owned_block must not increment when wallprecheck=false"); } /** @@ -244,14 +254,26 @@ private void leaveClearedInitializedContext() { @Override protected String getProfilerCommand() { // This suite verifies sampling and suppression for threads outside a - // tracing-context window. It relies on the default context-filter - // scope (filter="0") plus each worker thread explicitly registering - // itself via registerCurrentThreadForWallClockProfiling()/addThread(). - return "wall=1ms,wallprecheck=true"; + // tracing-context window. Owned-block suppression only applies to the + // unfiltered wall-clock scope (explicit empty filter=), and only while + // the thread stays outside the context window, so threads must not + // call addThread(). + return "wall=1ms,filter=,wallprecheck=true"; } protected String getPrecheckDisabledProfilerCommand() { - return "wall=1ms,wallprecheck=false"; + return "wall=1ms,filter=,wallprecheck=false"; + } + + private long samplesForThread(String threadName) { + long count = 0; + JfrEvents events = verifyEvents("datadog.MethodSample", false); + for (JfrEvent item : events) { + if (threadName.equals(item.getThreadName("eventThread"))) { + count++; + } + } + return count; } private WeightedSamples weightedSamplesForThread(String threadName) { diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/TaskBlockAssertions.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/TaskBlockAssertions.java new file mode 100644 index 0000000000..435a18dc8d --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/TaskBlockAssertions.java @@ -0,0 +1,94 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.JfrEvent; +import com.datadoghq.profiler.JfrEvents; +import com.datadoghq.profiler.JfrFrame; +import java.util.HashSet; +import java.util.Set; + +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** Assertions for the synchronous {@code datadog.TaskBlock} event contract. */ +final class TaskBlockAssertions { + private static final String BLOCKER = "blocker"; + private static final String UNBLOCKING_SPAN_ID = "unblockingSpanId"; + private static final String ANCHOR_SAMPLE_ID = "anchorSampleId"; + private static final String SUPPRESSED_SAMPLE_COUNT = "suppressedSampleCount"; + private static final String OBSERVED_BLOCKING_STATE = "observedBlockingState"; + private static final String CORRELATION_ID = "correlationId"; + + private TaskBlockAssertions() {} + + static void assertContains(JfrEvents events, long rootSpanId, long spanId, + long blocker, long unblockingSpanId) { + for (JfrEvent item : events) { + if (item.getLong(AbstractProfilerTest.LOCAL_ROOT_SPAN_ID, Long.MIN_VALUE) == rootSpanId + && item.getLong(AbstractProfilerTest.SPAN_ID, Long.MIN_VALUE) == spanId + && item.getLong(BLOCKER, Long.MIN_VALUE) == blocker + && item.getLong(UNBLOCKING_SPAN_ID, Long.MIN_VALUE) == unblockingSpanId) { + return; + } + } + throw new AssertionError("Expected TaskBlock blocker=" + blocker + + ", unblockingSpanId=" + unblockingSpanId); + } + + static void assertContainsObservedState(JfrEvents events, String expected) { + Set states = new HashSet<>(); + for (JfrEvent item : events) { + states.add(item.getString(OBSERVED_BLOCKING_STATE)); + } + assertTrue(states.contains(expected), () -> "Observed states: " + states); + } + + static void assertContainsStackTrace(JfrEvents events) { + int count = 0; + for (JfrEvent item : events) { + assertTrue(!item.getStackTrace().isEmpty()); + count++; + } + assertTrue(count > 0, "Expected a TaskBlock with a non-empty stack"); + } + + static void assertContainsNoStackTrace(JfrEvents events) { + int count = 0; + for (JfrEvent item : events) { + assertTrue(item.getStackTrace().isEmpty()); + count++; + } + assertTrue(count > 0, "Expected a TaskBlock without a stack"); + } + + static void assertContainsJavaType(JfrEvents events, String expected) { + for (JfrEvent item : events) { + if (!item.has(AbstractProfilerTest.STACK_TRACE)) continue; + for (JfrFrame frame : item.getStackTrace().frames()) { + String className = frame.className(); + if (className != null && className.contains(expected)) { + return; + } + } + } + throw new AssertionError("Expected TaskBlock stack type containing " + expected); + } + + static void assertNoCorrelationId(JfrEvents events) { + for (JfrEvent item : events) { + assertNull(item.get(CORRELATION_ID)); + } + } + + static void assertNoAnchorFields(JfrEvents events) { + for (JfrEvent item : events) { + assertNull(item.get(ANCHOR_SAMPLE_ID)); + assertNull(item.get(SUPPRESSED_SAMPLE_COUNT)); + } + } +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java index d44b3f8e66..72dabdf073 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java @@ -28,14 +28,14 @@ public class UnfilteredWallPrecheckTest extends AbstractProfilerTest { private static final int OSTHREAD_STATE_SLEEPING = 7; private static final long SLEEP_MILLIS = 300; private static final String PRE_EXISTING_THREAD_NAME = "unfiltered-precheck-existing"; - private static final String SUPPRESSED_RUN_COUNTER = "wc_signals_suppressed_sampled_run"; - private static final String UNOWNED_SUPPRESSED_COUNTER = "wc_unowned_blocked_suppressed"; + private static final String SUPPRESSED_OWNED_BLOCK_COUNTER = + "wc_signals_suppressed_owned_block"; private ExecutorService preExistingWorker; private Thread preExistingThread; /** - * Verifies that an untraced thread's owned sleeping run is sampled once and then suppressed. + * Verifies that an untraced thread's owned sleeping run is suppressed. * * @throws Exception if the worker cannot complete */ @@ -95,11 +95,9 @@ public void parkedPreExistingThreadOutsideContextWindowIsOwnedBlockSuppressed() */ @RetryingTest(3) public void unownedSleepAfterOwnedBlockUsesNormalSampling() throws Exception { - long unownedSuppressedBefore = unownedSuppressedSignals(); assertTrue( runPreExistingUnownedSleepingWorker() != 0, "Expected the setup block to register the worker"); - long unownedSuppressedAfter = unownedSuppressedSignals(); stopProfiler(); @@ -107,12 +105,6 @@ public void unownedSleepAfterOwnedBlockUsesNormalSampling() throws Exception { assertTrue( sampleCount >= 10, "Expected normal MethodSample volume for an unowned sleep, got: " + sampleCount); - if (unownedSuppressedBefore >= 0) { - assertEquals( - unownedSuppressedBefore, - unownedSuppressedAfter, - "Unfiltered mode must not use observation-only unowned suppression"); - } } /** @@ -156,6 +148,7 @@ public void unregisteredThreadUsesNormalSampling() throws Exception { */ @RetryingTest(3) public void postStartSleepingThreadLazilyRegistersOwnedBlock() throws Exception { + long suppressedBefore = suppressedSignals(); String threadName = "unfiltered-precheck-post-start"; long registrationsBefore = profiler.getDebugCounters().getOrDefault("thread_registry_hook_reregistration", -1L); @@ -171,6 +164,7 @@ public void postStartSleepingThreadLazilyRegistersOwnedBlock() throws Exception stopProfiler(); assertSuppressedSamples(threadName); + assertOwnedBlockSuppressionObserved(suppressedBefore); } @Override @@ -291,19 +285,18 @@ private void assertOwnedBlockSuppressionObserved(long suppressedBefore) { } private long suppressedSignals() { - return profiler.getDebugCounters().getOrDefault(SUPPRESSED_RUN_COUNTER, -1L); - } - - private long unownedSuppressedSignals() { - return profiler.getDebugCounters().getOrDefault(UNOWNED_SUPPRESSED_COUNTER, -1L); + return profiler.getDebugCounters().getOrDefault(SUPPRESSED_OWNED_BLOCK_COUNTER, -1L); } private void assertSuppressedSamples(String threadName) { long sampleCount = samplesForThread(threadName); - assertTrue(sampleCount > 0, "Expected the owned block run to be sampled once"); + assertTrue( + sampleCount >= 1, + "Expected the owned block's first MethodSample to be retained"); assertTrue( sampleCount < 10, - "Expected nearly no samples from owned block thread, got: " + sampleCount); + "Expected samples after the first owned-block sample to be suppressed, got: " + + sampleCount); } private long samplesForThread(String threadName) { diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/WallclockMitigationsCombinedTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/WallclockMitigationsCombinedTest.java index 00b51d9ba2..77319c13d2 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/WallclockMitigationsCombinedTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/WallclockMitigationsCombinedTest.java @@ -5,6 +5,7 @@ package com.datadoghq.profiler.wallclock; +import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertTrue; import com.datadoghq.profiler.AbstractProfilerTest; @@ -20,15 +21,12 @@ import java.util.concurrent.CountDownLatch; import java.util.concurrent.atomic.AtomicBoolean; -/** - * Verifies once-per-run suppression ({@code wallprecheck=true}) with a mix of sleeping, - * parked, and runnable threads. - */ +/** Verifies that {@code wallprecheck=true} does not suppress context-scoped threads. */ public class WallclockMitigationsCombinedTest extends AbstractProfilerTest { private static final int OSTHREAD_STATE_SLEEPING = 7; @Test - public void precheckAndParkSuppressionWorkTogether() throws Exception { + public void contextScopedThreadsRemainSampled() throws Exception { Assumptions.assumeTrue(!Platform.isJ9()); Assumptions.assumeTrue( Platform.isJavaVersionAtLeast(11), @@ -36,6 +34,8 @@ public void precheckAndParkSuppressionWorkTogether() throws Exception { CountDownLatch ready = new CountDownLatch(3); AtomicBoolean stop = new AtomicBoolean(false); + long suppressedBefore = profiler.getDebugCounters() + .getOrDefault("wc_signals_suppressed_owned_block", 0L); Thread sleeping = new Thread( @@ -106,20 +106,17 @@ public void precheckAndParkSuppressionWorkTogether() throws Exception { long parkedSamples = samplesByThread.getOrDefault("combined-parked", 0L); long runnableSamples = samplesByThread.getOrDefault("combined-runnable", 0L); - assertTrue(sleepingSamples < 10, - "Expected nearly no samples from owned sleeping thread, got: " + sleepingSamples); + assertTrue(sleepingSamples > 0, + "Expected samples from context-scoped sleeping thread, got: " + sleepingSamples); assertTrue(parkedSamples > 0, "Expected samples from traced parked thread, got: " + parkedSamples); assertTrue(runnableSamples > 0, "Expected samples from runnable thread, got: " + runnableSamples); - // Sleeping thread's suppression counter must have incremented. - Map counters = profiler.getDebugCounters(); - if (counters.containsKey("wc_signals_suppressed_sampled_run")) { - assertTrue( - counters.get("wc_signals_suppressed_sampled_run") > 0, - "Expected once-per-run suppression counter to increase"); - } + long suppressedAfter = profiler.getDebugCounters() + .getOrDefault("wc_signals_suppressed_owned_block", 0L); + assertEquals(suppressedBefore, suppressedAfter, + "Context-scoped blocked threads must not be signal-suppression candidates"); } @Override From 940d2e0c9dcdaf0aaecadef23437b5818349176c Mon Sep 17 00:00:00 2001 From: Paul Fournillon Date: Tue, 20 Oct 2026 15:30:35 +0200 Subject: [PATCH 2/6] fix: reset TaskBlock state when returning a thread object to the pool --- ddprof-lib/src/main/cpp/threadLocalData.cpp | 3 ++ ddprof-lib/src/main/cpp/threadLocalData.h | 6 ++- .../src/test/cpp/threadLocalDataPool_ut.cpp | 50 +++++++++++++++++++ 3 files changed, 58 insertions(+), 1 deletion(-) diff --git a/ddprof-lib/src/main/cpp/threadLocalData.cpp b/ddprof-lib/src/main/cpp/threadLocalData.cpp index 88840bfbd8..ab794b8505 100644 --- a/ddprof-lib/src/main/cpp/threadLocalData.cpp +++ b/ddprof-lib/src/main/cpp/threadLocalData.cpp @@ -170,6 +170,9 @@ void ProfiledThread::unclaimAndReset() { _call_trace_id = 0; _recording_epoch = 0; _park_block_token = 0; + _task_block_start_ticks = 0; + _task_block_token = 0; + _task_block_context = {}; _filter_slot_id = -1; _init_window = 0; _signal_depth = 0; diff --git a/ddprof-lib/src/main/cpp/threadLocalData.h b/ddprof-lib/src/main/cpp/threadLocalData.h index e29d415018..66fb0450cb 100644 --- a/ddprof-lib/src/main/cpp/threadLocalData.h +++ b/ddprof-lib/src/main/cpp/threadLocalData.h @@ -200,6 +200,9 @@ class ProfiledThread : public ThreadLocalData { u32 recording_epoch; u32 misc_flags; u64 park_block_token; + u64 task_block_start_ticks; + u64 task_block_token; + Context task_block_context; int filter_slot_id; uint8_t init_window; int signal_depth; @@ -214,7 +217,8 @@ class ProfiledThread : public ThreadLocalData { __atomic_load_n(&_crash_depth, __ATOMIC_RELAXED), _cpu_epoch, _wall_epoch, _call_trace_id, _recording_epoch, __atomic_load_n(&_misc_flags, __ATOMIC_RELAXED), - _park_block_token, _filter_slot_id, _init_window, + _park_block_token, _task_block_start_ticks, _task_block_token, + _task_block_context, _filter_slot_id, _init_window, __atomic_load_n(&_signal_depth, __ATOMIC_RELAXED), _in_critical_section, _otel_ctx_initialized, _otel_local_root_span_id }; diff --git a/ddprof-lib/src/test/cpp/threadLocalDataPool_ut.cpp b/ddprof-lib/src/test/cpp/threadLocalDataPool_ut.cpp index 4c11c2af16..b635474cb4 100644 --- a/ddprof-lib/src/test/cpp/threadLocalDataPool_ut.cpp +++ b/ddprof-lib/src/test/cpp/threadLocalDataPool_ut.cpp @@ -12,6 +12,7 @@ #include "threadLocalData.inline.h" #include "counters.h" +#include #include #include @@ -126,6 +127,41 @@ TEST_F(ThreadLocalDataPoolTest, reclaimedSlotHasResetState) { ThreadLocalDataPool::destroyForTest(pool); } +TEST_F(ThreadLocalDataPoolTest, reclaimedSlotCanBeginTaskBlockAfterAbandonedInterval) { + std::unique_ptr pool( + ThreadLocalDataPool::createForTest(1), ThreadLocalDataPool::destroyForTest); + + ProfiledThread* first = pool->claimForTest(100); + ASSERT_NE(first, nullptr); + Context first_context{}; + first_context.spanId = 123; + ASSERT_TRUE(first->taskBlockEnter(2048, 12345, first_context)); + + // The first thread exits without ending its interval. Reclaiming its slot + // must let a different thread start and finish an independent interval. + ASSERT_TRUE(pool->unclaimForTest(first)); + ProfiledThread* second = pool->claimForTest(200); + ASSERT_EQ(second, first); + EXPECT_EQ(second->tid(), 200); + + Context second_context{}; + second_context.rootSpanId = 456; + second_context.setTag(0, 789); + ASSERT_TRUE(second->taskBlockEnter(4096, 67890, second_context)); + + u64 start_ticks = 0; + Context exited_context{}; + EXPECT_FALSE(second->taskBlockExit(2048, start_ticks, exited_context)); + ASSERT_TRUE(second->taskBlockExit(4096, start_ticks, exited_context)); + EXPECT_EQ(start_ticks, 67890ULL); + EXPECT_EQ(exited_context.spanId, second_context.spanId); + EXPECT_EQ(exited_context.rootSpanId, second_context.rootSpanId); + for (u32 i = 0; i < DD_TAGS_CAPACITY; i++) { + EXPECT_EQ(exited_context.getTag(i), second_context.getTag(i)); + } + EXPECT_TRUE(pool->unclaimForTest(second)); +} + // Broader companion to reclaimedSlotHasResetState above, which only checks // filterSlotId and _in_critical_section. This dirties every field // unclaimAndReset() is responsible for and asserts the result matches a @@ -154,6 +190,13 @@ TEST(ProfiledThreadTest, UnclaimAndResetMatchesFreshInstance) { dirty->setJavaThread(true); ASSERT_TRUE(dirty->parkEnter()); dirty->setParkBlockToken(0x1234); + Context task_block_context{}; + task_block_context.spanId = 0x6000; + task_block_context.rootSpanId = 0x7000; + for (u32 i = 0; i < DD_TAGS_CAPACITY; i++) { + task_block_context.setTag(i, 0x100 + i); + } + ASSERT_TRUE(dirty->taskBlockEnter(0x8000, 0x9000, task_block_context)); dirty->setFilterSlotId(42); dirty->startInitWindow(); dirty->enterSignalScope(); @@ -193,6 +236,13 @@ TEST(ProfiledThreadTest, UnclaimAndResetMatchesFreshInstance) { EXPECT_EQ(reset_snapshot.recording_epoch, fresh_snapshot.recording_epoch); EXPECT_EQ(reset_snapshot.misc_flags, fresh_snapshot.misc_flags); EXPECT_EQ(reset_snapshot.park_block_token, fresh_snapshot.park_block_token); + EXPECT_EQ(reset_snapshot.task_block_start_ticks, fresh_snapshot.task_block_start_ticks); + EXPECT_EQ(reset_snapshot.task_block_token, fresh_snapshot.task_block_token); + EXPECT_EQ(reset_snapshot.task_block_context.spanId, fresh_snapshot.task_block_context.spanId); + EXPECT_EQ(reset_snapshot.task_block_context.rootSpanId, fresh_snapshot.task_block_context.rootSpanId); + for (u32 i = 0; i < DD_TAGS_CAPACITY; i++) { + EXPECT_EQ(reset_snapshot.task_block_context.getTag(i), fresh_snapshot.task_block_context.getTag(i)); + } EXPECT_EQ(reset_snapshot.filter_slot_id, fresh_snapshot.filter_slot_id); EXPECT_EQ(reset_snapshot.init_window, fresh_snapshot.init_window); EXPECT_EQ(reset_snapshot.signal_depth, fresh_snapshot.signal_depth); From 6c2846e29f92b32771970fb55ef4c5f6495d7448 Mon Sep 17 00:00:00 2001 From: Paul Fournillon Date: Tue, 20 Oct 2026 18:31:02 +0200 Subject: [PATCH 3/6] test: assert weighted coverage for unowned wall-clock sleeps --- .../wallclock/UnfilteredWallPrecheckTest.java | 24 ++++++++++++++----- 1 file changed, 18 insertions(+), 6 deletions(-) diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java index 72dabdf073..d00a835f82 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnfilteredWallPrecheckTest.java @@ -88,23 +88,35 @@ public void parkedPreExistingThreadOutsideContextWindowIsOwnedBlockSuppressed() } /** - * Verifies that a thread which already owns a registry slot still receives ordinary per-signal - * sampling outside an explicitly owned block. + * Verifies that an unowned sleep after an owned block preserves sampling weight. The fallback + * combines suppressed observations into weighted events, so event count is not coverage. * * @throws Exception if the worker cannot complete */ @RetryingTest(3) - public void unownedSleepAfterOwnedBlockUsesNormalSampling() throws Exception { + public void unownedSleepAfterOwnedBlockPreservesSampleWeight() throws Exception { assertTrue( runPreExistingUnownedSleepingWorker() != 0, "Expected the setup block to register the worker"); stopProfiler(); - long sampleCount = samplesForThread(PRE_EXISTING_THREAD_NAME); + long sampleCount = 0; + long totalWeight = 0; + for (JfrEvent event : verifyEvents("datadog.MethodSample", false)) { + if (PRE_EXISTING_THREAD_NAME.equals(event.getThreadName("eventThread"))) { + sampleCount++; + totalWeight += event.getLong(WEIGHT, 0); + } + } assertTrue( - sampleCount >= 10, - "Expected normal MethodSample volume for an unowned sleep, got: " + sampleCount); + totalWeight >= 10, + "Expected at least 10 represented observations for the unowned sleep, count=" + + sampleCount + ", weight=" + totalWeight); + assertTrue( + totalWeight > sampleCount, + "Expected suppressed observations to be represented by weight, count=" + + sampleCount + ", weight=" + totalWeight); } /** From 74a55d55a599bcb9756119e45a4479266982c17f Mon Sep 17 00:00:00 2001 From: Paul Fournillon Date: Tue, 20 Oct 2026 18:35:57 +0200 Subject: [PATCH 4/6] fix: preserve unowned wall-tail traces across JFR dumps --- ddprof-lib/src/main/cpp/javaApi.cpp | 15 +++ ddprof-lib/src/main/cpp/profiler.cpp | 54 +++++++- ddprof-lib/src/main/cpp/profiler.h | 19 ++- ddprof-lib/src/main/cpp/wallClock.cpp | 126 ++++++++++++++---- ddprof-lib/src/main/cpp/wallClock.h | 7 + .../src/main/cpp/wallClockBlockTracker.h | 15 ++- .../profiler/JavaProfilerTestSupport.java | 20 +++ ddprof-lib/src/test/cpp/park_state_ut.cpp | 17 ++- .../src/test/cpp/wallClockBlockTracker_ut.cpp | 2 +- .../src/test/cpp/wallTailRecording_ut.cpp | 72 ++++++++++ .../wallclock/UnownedBlockedTailDumpTest.java | 89 +++++++++++++ 11 files changed, 393 insertions(+), 43 deletions(-) create mode 100644 ddprof-lib/src/test/cpp/wallTailRecording_ut.cpp create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnownedBlockedTailDumpTest.java diff --git a/ddprof-lib/src/main/cpp/javaApi.cpp b/ddprof-lib/src/main/cpp/javaApi.cpp index 496ac75d36..25b74bb48b 100644 --- a/ddprof-lib/src/main/cpp/javaApi.cpp +++ b/ddprof-lib/src/main/cpp/javaApi.cpp @@ -345,6 +345,21 @@ Java_com_datadoghq_profiler_JavaProfilerTestSupport_isThreadRegistryActiveForTes return Profiler::instance()->threadFilter()->registryActive(); } +extern "C" DLLEXPORT jboolean JNICALL +Java_com_datadoghq_profiler_JavaProfilerTestSupport_recordUnownedWallTailAcrossDumpForTest0( + JNIEnv *env, jclass unused, jthread thread, jstring snapshot, + jboolean before_publication, jboolean reset_before_tail) { +#ifdef DEBUG + JniString path(env, snapshot); + return BaseWallClock::recordUnownedWallTailAcrossDumpForTest( + thread, path.c_str(), path.length(), before_publication == JNI_TRUE, + reset_before_tail == JNI_TRUE) + ? JNI_TRUE : JNI_FALSE; +#else + return JNI_FALSE; +#endif +} + extern "C" DLLEXPORT void JNICALL Java_com_datadoghq_profiler_JavaProfiler_recordSettingEvent0( JNIEnv *env, jclass unused, jstring name, jstring value, jstring unit) { diff --git a/ddprof-lib/src/main/cpp/profiler.cpp b/ddprof-lib/src/main/cpp/profiler.cpp index 4f422a77ff..a38862a9ee 100644 --- a/ddprof-lib/src/main/cpp/profiler.cpp +++ b/ddprof-lib/src/main/cpp/profiler.cpp @@ -679,9 +679,52 @@ void Profiler::recordDeferredSample(int tid, u64 call_trace_id, jint event_type, _locks[lock_index].unlock(); } +void Profiler::recordUnownedBlockedTail( + int tid, WallClockBlockTracker::BlockState *slot, u64 weight) { + atomicIncRelaxed(_total_samples); + + u32 lock_index = getLockIndex(tid); + if (!_locks[lock_index].tryLock() && + !_locks[lock_index = (lock_index + 1) % CONCURRENCY_LEVEL].tryLock() && + !_locks[lock_index = (lock_index + 2) % CONCURRENCY_LEVEL].tryLock()) { + atomicIncRelaxed(_failures[-ticks_skipped]); + slot->discardUnownedBlockedTail(); + return; + } + + // Preparation leaves this reference visible to the liveness checker. Load it + // under the stripe as a slot reset may have discarded it since preparation. + u64 call_trace_id = slot->unowned_blocked_call_trace_id.load(std::memory_order_acquire); + OSThreadState state = slot->unowned_blocked_state.load(std::memory_order_acquire); + if (call_trace_id != 0 && state != OSThreadState::UNKNOWN) { + ExecutionEvent event; + event._thread_state = state; + event._execution_mode = ExecutionMode::UNKNOWN; + event._weight = weight; + _jfr.recordEvent(lock_index, tid, call_trace_id, BCI_WALL, &event); + } + slot->discardUnownedBlockedTail(); + _locks[lock_index].unlock(); +} + bool Profiler::recordSample(void *ucontext, u64 counter, int tid, - jint event_type, u64 call_trace_id, Event *event, - u64 *recorded_call_trace_id) { + jint event_type, u64 call_trace_id, Event *event) { + return recordSampleImpl(ucontext, counter, tid, event_type, + call_trace_id, event, nullptr); +} + +bool Profiler::recordWallSample( + void *ucontext, u64 counter, int tid, u64 call_trace_id, + ExecutionEvent *event, WallClockBlockTracker::BlockState *unowned_slot) { + return recordSampleImpl(ucontext, counter, tid, BCI_WALL, + call_trace_id, event, unowned_slot); +} + +template +bool Profiler::recordSampleImpl( + void *ucontext, u64 counter, int tid, jint event_type, + u64 call_trace_id, Event *event, + WallClockBlockTracker::BlockState *unowned_slot) { atomicIncRelaxed(_total_samples); u32 lock_index = getLockIndex(tid); @@ -744,8 +787,11 @@ bool Profiler::recordSample(void *ucontext, u64 counter, int tid, #endif // COUNTERS } bool recorded = _jfr.recordEvent(lock_index, tid, call_trace_id, event_type, event); - if (recorded && recorded_call_trace_id != nullptr) { - *recorded_call_trace_id = call_trace_id; + if constexpr (cache_unowned_wall) { + if (recorded && call_trace_id != 0 && unowned_slot != nullptr) { + unowned_slot->recordUnownedBlockedSample( + call_trace_id, static_cast(event)->_thread_state); + } } _locks[lock_index].unlock(); diff --git a/ddprof-lib/src/main/cpp/profiler.h b/ddprof-lib/src/main/cpp/profiler.h index 7a7162392c..f433032724 100644 --- a/ddprof-lib/src/main/cpp/profiler.h +++ b/ddprof-lib/src/main/cpp/profiler.h @@ -208,6 +208,11 @@ class alignas(alignof(SpinLock)) Profiler { // that turns it into DICTIONARY_DRAIN_TIMEOUTS and a warning. void reportDrainTimeout(const char *what); void unlockAll(); + // Compile the wall-only cache publication out of the CPU/other sample paths. + template + bool recordSampleImpl(void *ucontext, u64 weight, int tid, jint event_type, + u64 call_trace_id, Event *event, + WallClockBlockTracker::BlockState *unowned_slot); bool beginTaskBlockRotation(); void endTaskBlockRotation(); @@ -282,7 +287,7 @@ class alignas(alignof(SpinLock)) Profiler { // Protects wall-clock unowned-block fallback tail traces (cached in // WallClockBlockTracker::BlockState) from being dropped by a chunk - // rotation before flushUnownedBlockedTail() emits them. The tracker lives + // rotation before recordUnownedBlockedTail() emits them. The tracker lives // in the Profiler singleton, so this is registered once rather than // per-recording. registerLivenessChecker([this](CallTraceIdSet& buffer) { @@ -493,8 +498,16 @@ class alignas(alignof(SpinLock)) Profiler { ASGCT_CallFrame *frames, int lock_index, bool skip_hook_prefix); bool recordSample(void *ucontext, u64 weight, int tid, jint event_type, - u64 call_trace_id, Event *event, - u64 *recorded_call_trace_id = nullptr); + u64 call_trace_id, Event *event); + // Publishes a reusable unowned-block trace before releasing the writer stripe, + // so dump's lockAll() cannot retire it between insertion and publication. + bool recordWallSample(void *ucontext, u64 weight, int tid, u64 call_trace_id, + ExecutionEvent *event, + WallClockBlockTracker::BlockState *unowned_slot); + // Reads and releases the cached trace while holding a writer stripe. Failed + // acquisition drops the tail, matching recordDeferredSample's drop policy. + void recordUnownedBlockedTail(int tid, WallClockBlockTracker::BlockState *slot, + u64 weight); // Delegated sample path: stack-walking is performed by the HotSpot JFR // RequestStackTrace extension (the JVM emits the stack trace into its own // JFR recording). We only emit the CPU/wall sample event with no diff --git a/ddprof-lib/src/main/cpp/wallClock.cpp b/ddprof-lib/src/main/cpp/wallClock.cpp index 77c94e2fb5..859607a5cd 100644 --- a/ddprof-lib/src/main/cpp/wallClock.cpp +++ b/ddprof-lib/src/main/cpp/wallClock.cpp @@ -62,6 +62,7 @@ struct WallPrecheckResult { WallClockBlockTracker::BlockState* unowned_weight_slot = nullptr; u64 unowned_weight = 1; bool flush_unowned_tail = false; + WallClockBlockTracker::BlockState* unowned_tail_slot = nullptr; u64 flush_call_trace_id = 0; u64 flush_weight = 0; OSThreadState flush_state = OSThreadState::UNKNOWN; @@ -82,8 +83,12 @@ bool BaseWallClock::suppressAlreadySampled(const ThreadEntry& entry) { return false; } -static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, - bool precheck) { +static inline WallPrecheckResult prepareWallPrecheck( + ProfiledThread* current, bool precheck +#ifdef DEBUG + , OSThreadState observed_state_for_test = OSThreadState::UNKNOWN +#endif + ) { WallPrecheckResult result; if (current == nullptr || !precheck || hasKnownActiveTraceContext(current)) { return result; @@ -131,7 +136,12 @@ static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, return result; } +#ifdef DEBUG + result.observed_state = observed_state_for_test != OSThreadState::UNKNOWN + ? observed_state_for_test : getOSThreadState(); +#else result.observed_state = getOSThreadState(); +#endif result.observed_state_valid = true; if (isPrecheckSuppressionState(result.observed_state)) { if (!block_slot->shouldRecordUnownedBlockedSample()) { @@ -142,15 +152,15 @@ static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, result.unowned_weight_slot = block_slot; result.unowned_weight = block_slot->consumeUnownedBlockedWeight(); } else { - result.flush_unowned_tail = block_slot->flushUnownedBlockedTail( + result.flush_unowned_tail = block_slot->prepareUnownedBlockedTail( result.flush_call_trace_id, result.flush_weight, result.flush_state); + if (result.flush_unowned_tail) result.unowned_tail_slot = block_slot; } return result; } static inline void finishWallPrecheck(const WallPrecheckResult& precheck, - bool recorded, - u64 recorded_call_trace_id = 0) { + bool recorded) { if (recorded && precheck.owned_block_slot != nullptr) { precheck.owned_block_slot->markBlockGenerationSampled( precheck.owned_block_generation); @@ -160,31 +170,96 @@ static inline void finishWallPrecheck(const WallPrecheckResult& precheck, precheck.unowned_weight); } else if (recorded && precheck.unowned_weight_slot != nullptr) { Counters::increment(WC_UNOWNED_BLOCKED_RECORDED); - if (recorded_call_trace_id != 0) { - precheck.unowned_weight_slot->recordUnownedBlockedSample( - recorded_call_trace_id, precheck.observed_state); - } } } -static inline void recordDeferredWallSample(int tid, u64 call_trace_id, - ExecutionEvent* event) { - Profiler::instance()->recordDeferredSample(tid, call_trace_id, BCI_WALL, event); -} - static inline void emitUnownedBlockedTailForWallPrecheck( int tid, const WallPrecheckResult& precheck) { if (!precheck.flush_unowned_tail || precheck.flush_call_trace_id == 0) { return; } - ExecutionEvent flush_event; - flush_event._thread_state = precheck.flush_state; - flush_event._execution_mode = ExecutionMode::UNKNOWN; - flush_event._weight = precheck.flush_weight; - recordDeferredWallSample(tid, precheck.flush_call_trace_id, &flush_event); + Profiler::instance()->recordUnownedBlockedTail( + tid, precheck.unowned_tail_slot, precheck.flush_weight); } +#ifdef DEBUG +// Only the synchronous JNI test driver supplies this argument. It inserts a +// real dump at a boundary outside the profiler stripe locks, without waiting +// inside a signal handler or adding hooks to release builds. +struct WallPrecheckDumpTest { + jthread thread; + const char* path; + int path_length; + bool before_publication; + bool reset_before_tail; + Error error = Error::OK; + + void dumpAtBoundary(bool publication) { + if (publication == before_publication) { + error = Profiler::instance()->dump(path, path_length); + } + } +}; + +static inline bool recordAsgctWallSample( + void* ucontext, u64 counter, int tid, u64 call_trace_id, + ExecutionEvent* event, const WallPrecheckResult& precheck, + WallPrecheckDumpTest* dump_test = nullptr) { + if (dump_test != nullptr) { + if (precheck.flush_unowned_tail) dump_test->dumpAtBoundary(false); + if (precheck.flush_unowned_tail && dump_test->reset_before_tail) { + precheck.unowned_tail_slot->resetUnownedBlockedSampling(); + } + // A synchronous JNI driver has no signal ucontext. Capture a real Java + // stack through JVMTI, then use recordSample's existing trace-reuse path. + call_trace_id = Profiler::instance()->recordJVMTISample( + counter, tid, dump_test->thread, BCI_WALL, event, true); + if (call_trace_id == 0) return false; + } + bool recorded = Profiler::instance()->recordWallSample( + ucontext, counter, tid, call_trace_id, event, precheck.unowned_weight_slot); + if (dump_test != nullptr && recorded && precheck.unowned_weight_slot != nullptr) { + dump_test->dumpAtBoundary(true); + } + finishWallPrecheck(precheck, recorded); + emitUnownedBlockedTailForWallPrecheck(tid, precheck); + return recorded; +} + +bool BaseWallClock::recordUnownedWallTailAcrossDumpForTest( + jthread thread, const char* path, int path_length, bool before_publication, + bool reset_before_tail) { + SignalBlocker blocker; + Profiler* profiler = Profiler::instance(); + ProfiledThread* current = ProfiledThread::initCurrentThreadSignalSafe(); + ThreadFilter* registry = profiler->threadFilter(); + if (current == nullptr || !profiler->isRunning() || + !registry->unfilteredWallTrackingActive()) return false; + ThreadFilter::SlotID slot_id = registry->ensureCurrentThreadSlot(current); + WallClockBlockTracker::BlockState* slot = profiler->blockTracker()->slotForId(slot_id); + if (slot == nullptr || slot->activeBlockOwner() != BlockRunOwner::NONE) return false; + slot->resetUnownedBlockedSampling(); + + WallPrecheckDumpTest dump_test{thread, path, path_length, before_publication, reset_before_tail}; + ExecutionEvent event; + event._thread_state = OSThreadState::SLEEPING; + event._execution_mode = ExecutionMode::JAVA; + WallPrecheckResult first = prepareWallPrecheck(current, true, OSThreadState::SLEEPING); + if (first.suppress || first.unowned_weight_slot != slot) return false; + if (!recordAsgctWallSample(nullptr, 1, current->tid(), 0, &event, first, &dump_test) || + dump_test.error) return false; + + // One further blocked observation contributes exactly one pending unit. + if (!prepareWallPrecheck(current, true, OSThreadState::SLEEPING).suppress) return false; + WallPrecheckResult tail = prepareWallPrecheck(current, true, OSThreadState::RUNNABLE); + if (!tail.flush_unowned_tail || tail.flush_weight != 1) return false; + event._thread_state = OSThreadState::RUNNABLE; + return recordAsgctWallSample(nullptr, 1, current->tid(), 0, &event, tail, &dump_test) && + !dump_test.error; +} +#endif + bool BaseWallClock::inSyscall(void *ucontext) { StackFrame frame(ucontext); uintptr_t pc = frame.pc(); @@ -301,13 +376,14 @@ void WallClockASGCT::signalHandler(int signo, siginfo_t *siginfo, void *ucontext event._thread_state = state; event._execution_mode = mode; event._weight = precheck.unowned_weight; - u64 recorded_call_trace_id = 0; - bool recorded = Profiler::instance()->recordSample(ucontext, last_sample, tid, - BCI_WALL, call_trace_id, - &event, - &recorded_call_trace_id); - finishWallPrecheck(precheck, recorded, recorded_call_trace_id); +#ifdef DEBUG + recordAsgctWallSample(ucontext, last_sample, tid, call_trace_id, &event, precheck); +#else + bool recorded = Profiler::instance()->recordWallSample( + ucontext, last_sample, tid, call_trace_id, &event, precheck.unowned_weight_slot); + finishWallPrecheck(precheck, recorded); emitUnownedBlockedTailForWallPrecheck(tid, precheck); +#endif } } diff --git a/ddprof-lib/src/main/cpp/wallClock.h b/ddprof-lib/src/main/cpp/wallClock.h index c63804ba97..1f11c31f3a 100644 --- a/ddprof-lib/src/main/cpp/wallClock.h +++ b/ddprof-lib/src/main/cpp/wallClock.h @@ -239,6 +239,13 @@ class BaseWallClock : public Engine { static std::atomic _force_start_failure_for_test; public: #endif +#ifdef DEBUG + // Drives the real precheck/recording path with controlled OS-state inputs + // and an intervening JFR dump. Called synchronously from the JNI test hook. + static bool recordUnownedWallTailAcrossDumpForTest( + jthread thread, const char* path, int path_length, bool before_publication, + bool reset_before_tail); +#endif }; class WallClockASGCT : public BaseWallClock { diff --git a/ddprof-lib/src/main/cpp/wallClockBlockTracker.h b/ddprof-lib/src/main/cpp/wallClockBlockTracker.h index 47a1ff1488..3c9af54192 100644 --- a/ddprof-lib/src/main/cpp/wallClockBlockTracker.h +++ b/ddprof-lib/src/main/cpp/wallClockBlockTracker.h @@ -165,17 +165,24 @@ class WallClockBlockTracker { unowned_blocked_state.store(state, std::memory_order_relaxed); unowned_blocked_call_trace_id.store(call_trace_id, std::memory_order_release); } - inline bool flushUnownedBlockedTail(u64& call_trace_id, u64& weight, + // Leave the trace published until the deferred writer holds a profiler + // stripe. Removing it here would let a dump retire it before the write. + inline bool prepareUnownedBlockedTail(u64& call_trace_id, u64& weight, OSThreadState& state) { - call_trace_id = unowned_blocked_call_trace_id.exchange(0, std::memory_order_acq_rel); + call_trace_id = unowned_blocked_call_trace_id.load(std::memory_order_acquire); weight = unowned_blocked_pending_weight.exchange(0, std::memory_order_relaxed); - state = unowned_blocked_state.exchange(OSThreadState::UNKNOWN, std::memory_order_relaxed); + state = unowned_blocked_state.load(std::memory_order_acquire); unowned_blocked_decision_count.store(0, std::memory_order_relaxed); if (call_trace_id == 0 || weight == 0 || state == OSThreadState::UNKNOWN) { + discardUnownedBlockedTail(); return false; } return true; } + inline void discardUnownedBlockedTail() { + unowned_blocked_state.store(OSThreadState::UNKNOWN, std::memory_order_relaxed); + unowned_blocked_call_trace_id.store(0, std::memory_order_release); + } // identity_slot supplies the context-window state, which lives on // ThreadFilter::Slot. See ThreadFilter::Slot::rawContextWindowState(). // On success the run is owned but not yet visible to readers; the @@ -329,7 +336,7 @@ class WallClockBlockTracker { bool hasActiveBlockRun(ThreadFilter::SlotID slot_id) const; // Liveness hook for CallTraceStorage::processTraces: a slot may cache a // call_trace_id for a still-blocked thread's weighted fallback tail - // (recordUnownedBlockedSample) well before flushUnownedBlockedTail() emits + // (recordUnownedBlockedSample) well before recordUnownedBlockedTail() emits // it. Without this, a chunk rotation racing that window drops the trace, // and the eventual deferred sample references an id with no constant-pool // entry in the chunk it lands in. diff --git a/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfilerTestSupport.java b/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfilerTestSupport.java index 69e435ea97..297a7aea93 100644 --- a/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfilerTestSupport.java +++ b/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfilerTestSupport.java @@ -37,9 +37,29 @@ public static boolean isThreadRegistryActiveForTest() { return isThreadRegistryActiveForTest0(); } + /** + * Records a blocked sample and its deferred tail through the native wall precheck path, + * inserting a real JFR dump at the selected boundary. Debug builds only. + * + * @param snapshot path receiving the chunk before the deferred tail + * @param beforePublication whether to dump between primary recording and precheck completion; + * otherwise dump between tail preparation and recording + * @param resetBeforeTail whether to reset the cached state after tail preparation + * @return whether both primary samples were recorded and the dump succeeded; + * always {@code false} outside debug builds + */ + public static boolean recordUnownedWallTailAcrossDumpForTest( + String snapshot, boolean beforePublication, boolean resetBeforeTail) { + return recordUnownedWallTailAcrossDumpForTest0( + Thread.currentThread(), snapshot, beforePublication, resetBeforeTail); + } + private static native void setForceWallStartFailureForTest0(boolean force); private static native boolean isForceWallStartFailureArmedForTest0(); private static native boolean isThreadRegistryActiveForTest0(); + + private static native boolean recordUnownedWallTailAcrossDumpForTest0( + Thread thread, String snapshot, boolean beforePublication, boolean resetBeforeTail); } diff --git a/ddprof-lib/src/test/cpp/park_state_ut.cpp b/ddprof-lib/src/test/cpp/park_state_ut.cpp index 42fa453a16..cb08cbbbf8 100644 --- a/ddprof-lib/src/test/cpp/park_state_ut.cpp +++ b/ddprof-lib/src/test/cpp/park_state_ut.cpp @@ -189,12 +189,17 @@ TEST(WallClockOncePerRunFilterTest, UnownedBlockedFallbackFlushesTailWeightWithR u64 call_trace_id = 0; u64 weight = 0; OSThreadState state = OSThreadState::UNKNOWN; - EXPECT_TRUE(slot.flushUnownedBlockedTail(call_trace_id, weight, state)); + EXPECT_TRUE(slot.prepareUnownedBlockedTail(call_trace_id, weight, state)); EXPECT_EQ(42ULL, call_trace_id); EXPECT_EQ(WallClockBlockTracker::BlockState::kUnownedBlockedFallbackRatio - 1, weight); EXPECT_EQ(OSThreadState::SLEEPING, state); - EXPECT_FALSE(slot.flushUnownedBlockedTail(call_trace_id, weight, state)); + // The dump-time liveness hook must still see the ID after preparation. + EXPECT_EQ(42ULL, slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire)); + slot.discardUnownedBlockedTail(); + EXPECT_EQ(0ULL, slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire)); + + EXPECT_FALSE(slot.prepareUnownedBlockedTail(call_trace_id, weight, state)); EXPECT_TRUE(slot.shouldRecordUnownedBlockedSample()); EXPECT_EQ(1ULL, slot.consumeUnownedBlockedWeight()); } @@ -212,7 +217,7 @@ TEST(WallClockOncePerRunFilterTest, UnownedBlockedFallbackDoesNotFlushWithoutRec u64 call_trace_id = 0; u64 weight = 0; OSThreadState state = OSThreadState::UNKNOWN; - EXPECT_FALSE(slot.flushUnownedBlockedTail(call_trace_id, weight, state)); + EXPECT_FALSE(slot.prepareUnownedBlockedTail(call_trace_id, weight, state)); EXPECT_EQ(0ULL, call_trace_id); EXPECT_EQ(WallClockBlockTracker::BlockState::kUnownedBlockedFallbackRatio - 1, weight); EXPECT_EQ(OSThreadState::UNKNOWN, state); @@ -235,7 +240,7 @@ TEST(WallClockOncePerRunFilterTest, UnownedBlockedFallbackDoesNotFlushWithoutSav u64 call_trace_id = 0; u64 weight = 0; OSThreadState state = OSThreadState::SLEEPING; - EXPECT_FALSE(slot.flushUnownedBlockedTail(call_trace_id, weight, state)); + EXPECT_FALSE(slot.prepareUnownedBlockedTail(call_trace_id, weight, state)); EXPECT_EQ(42ULL, call_trace_id); EXPECT_EQ(WallClockBlockTracker::BlockState::kUnownedBlockedFallbackRatio - 1, weight); EXPECT_EQ(OSThreadState::UNKNOWN, state); @@ -267,7 +272,7 @@ TEST(WallClockOncePerRunFilterTest, UnownedBlockedTailStateConcurrentStress) { u64 call_trace_id = 0; u64 weight = 0; OSThreadState state = OSThreadState::UNKNOWN; - bool flushed = slot.flushUnownedBlockedTail(call_trace_id, weight, state); + bool flushed = slot.prepareUnownedBlockedTail(call_trace_id, weight, state); if (flushed && (call_trace_id == 0 || weight == 0 || state != OSThreadState::SLEEPING)) { @@ -291,7 +296,7 @@ TEST(WallClockOncePerRunFilterTest, UnownedBlockedTailStateConcurrentStress) { u64 call_trace_id = 0; u64 weight = 0; OSThreadState state = OSThreadState::UNKNOWN; - EXPECT_FALSE(slot.flushUnownedBlockedTail(call_trace_id, weight, state)); + EXPECT_FALSE(slot.prepareUnownedBlockedTail(call_trace_id, weight, state)); } TEST(WallClockOncePerRunFilterTest, FilterHelpersManageActiveBlockState) { diff --git a/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp b/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp index f2ca80c16d..ade9f300dc 100644 --- a/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp +++ b/ddprof-lib/src/test/cpp/wallClockBlockTracker_ut.cpp @@ -562,7 +562,7 @@ TEST_F(WallClockBlockTrackerTest, ContextEntryWithoutActiveBlockRunPreservesUnow u64 call_trace_id = 0, weight = 0; OSThreadState state = OSThreadState::UNKNOWN; - EXPECT_TRUE(block_slot->flushUnownedBlockedTail(call_trace_id, weight, state)); + EXPECT_TRUE(block_slot->prepareUnownedBlockedTail(call_trace_id, weight, state)); EXPECT_EQ(0xABCDULL, call_trace_id); EXPECT_EQ(2ULL, weight); EXPECT_EQ(OSThreadState::CONDVAR_WAIT, state); diff --git a/ddprof-lib/src/test/cpp/wallTailRecording_ut.cpp b/ddprof-lib/src/test/cpp/wallTailRecording_ut.cpp new file mode 100644 index 0000000000..3e9826744e --- /dev/null +++ b/ddprof-lib/src/test/cpp/wallTailRecording_ut.cpp @@ -0,0 +1,72 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +#include +#include "profiler.h" + +class ProfilerTestAccessor { +public: + static void lockAll(Profiler* profiler) { profiler->lockAll(); } + static void unlockAll(Profiler* profiler) { profiler->unlockAll(); } +}; + +namespace { +class HeldWriterStripes { + Profiler* _profiler; +public: + explicit HeldWriterStripes(Profiler* profiler) : _profiler(profiler) { + ProfilerTestAccessor::lockAll(_profiler); + } + ~HeldWriterStripes() { ProfilerTestAccessor::unlockAll(_profiler); } +}; +} + +TEST(WallTailRecordingTest, ContendedPrimaryDoesNotPublishAnUnrecordedTrace) { + Profiler* profiler = Profiler::instance(); + WallClockBlockTracker::BlockState slot; + slot.recordUnownedBlockedSample(42, OSThreadState::SLEEPING); + ExecutionEvent event; + event._thread_state = OSThreadState::SLEEPING; + + HeldWriterStripes held(profiler); + EXPECT_FALSE(profiler->recordWallSample(nullptr, 1, 1234, 43, &event, &slot)); + EXPECT_EQ(42ULL, slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire)); +} + +TEST(WallTailRecordingTest, ContendedTailIsDiscardedWithoutWaitingOrRetrying) { + Profiler* profiler = Profiler::instance(); + WallClockBlockTracker::BlockState slot; + slot.recordUnownedBlockedSample(42, OSThreadState::SLEEPING); + + HeldWriterStripes held(profiler); + profiler->recordUnownedBlockedTail(1234, &slot, 9); + EXPECT_EQ(0ULL, slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire)); + EXPECT_EQ(OSThreadState::UNKNOWN, slot.unowned_blocked_state.load(std::memory_order_acquire)); +} + +TEST(WallTailRecordingTest, InactiveRecordingDoesNotPublishAnUnrecordedTrace) { + // No recording is started in this native test binary. Supplying a trace ID + // exercises the JFR rejection path without requiring a JVM stack walk. + Profiler* profiler = Profiler::instance(); + WallClockBlockTracker::BlockState slot; + slot.recordUnownedBlockedSample(42, OSThreadState::SLEEPING); + ExecutionEvent event; + event._thread_state = OSThreadState::SLEEPING; + + EXPECT_FALSE(profiler->recordWallSample(nullptr, 1, 1234, 43, &event, &slot)); + EXPECT_EQ(42ULL, slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire)); +} + +TEST(WallTailRecordingTest, InactiveRecordingDiscardsTailAndReleasesWriterStripe) { + Profiler* profiler = Profiler::instance(); + WallClockBlockTracker::BlockState slot; + slot.recordUnownedBlockedSample(42, OSThreadState::SLEEPING); + + profiler->recordUnownedBlockedTail(1234, &slot, 9); + EXPECT_EQ(0ULL, slot.unowned_blocked_call_trace_id.load(std::memory_order_acquire)); + EXPECT_EQ(OSThreadState::UNKNOWN, slot.unowned_blocked_state.load(std::memory_order_acquire)); + // Acquiring all stripes after the rejected write verifies its unlock path. + HeldWriterStripes held(profiler); +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnownedBlockedTailDumpTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnownedBlockedTailDumpTest.java new file mode 100644 index 0000000000..4a3f6f602d --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/UnownedBlockedTailDumpTest.java @@ -0,0 +1,89 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import com.datadoghq.profiler.JavaProfilerTestSupport; +import com.datadoghq.profiler.JfrEvent; +import com.datadoghq.profiler.Platform; +import java.nio.file.Files; +import java.nio.file.Path; +import org.junit.jupiter.api.Assumptions; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.CsvSource; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** Reproduces missing tail stacks using real sampling writes, JFR dumps, and constant pools. */ +public class UnownedBlockedTailDumpTest extends AbstractProfilerTest { + /** + * Forces each unsafe interleaving without relying on timer scheduling or worker sleep durations. + * The debug driver controls only OS-state inputs, stack capture, and where the dump runs. + */ + @ParameterizedTest(name = "dumpAfterPrimary={0}, resetBeforeTail={1}") + @CsvSource({"true, false", "false, false", "false, true"}) + public void deferredTailRetainsItsStackAcrossDump(boolean beforePublication, boolean resetBeforeTail) + throws Exception { + Assumptions.assumeTrue(isDebugBuild(), "Requires the debug-only synchronous sampling driver"); + profiler.clearTraceContext(); + long threadId = Thread.currentThread().getId(); + Path snapshot = Files.createTempFile("unowned-tail-before-", ".jfr"); + try { + assertTrue(JavaProfilerTestSupport.recordUnownedWallTailAcrossDumpForTest( + snapshot.toAbsolutePath().toString(), beforePublication, resetBeforeTail), + "Failed to record the primary samples or dump the first chunk"); + stopProfiler(); + + // Positive controls: the initial blocked stack and the later fresh stack + // resolve correctly. Only the deferred tail reuses the retired trace ID. + assertSampleStack(verifyEvents(snapshot, "datadog.MethodSample", true), + threadId, "SLEEPING", "JAVA"); + assertSampleStack(verifyEvents("datadog.MethodSample"), threadId, "RUNNABLE", "JAVA"); + if (resetBeforeTail) { + for (JfrEvent event : verifyEvents("datadog.MethodSample")) { + if (Long.valueOf(threadId).equals(event.getThreadJavaId("eventThread"))) { + assertTrue(!"UNKNOWN".equals(event.getString("mode")), + "A reset tail must not emit a stale trace ID"); + } + } + } else { + assertSampleStack(verifyEvents("datadog.MethodSample"), threadId, "SLEEPING", "UNKNOWN"); + } + } finally { + if (!Boolean.getBoolean("ddprof_test.keep_jfrs")) { + Files.deleteIfExists(snapshot); + } + } + } + + /** Checks that the matching weighted sample resolves the Java stack captured by the driver. */ + private void assertSampleStack(Iterable events, long threadId, String state, String mode) { + int matching = 0; + for (JfrEvent event : events) { + if (Long.valueOf(threadId).equals(event.getThreadJavaId("eventThread")) + && state.equals(event.getString("state")) + && mode.equals(event.getString("mode"))) { + matching++; + assertEquals(1L, event.getLong(WEIGHT, 0)); + String stack = event.getStackTraceString(); + assertTrue(stack != null && stack.contains("UnownedBlockedTailDumpTest"), + "Missing stack for " + state + "/" + mode + " sample"); + } + } + assertTrue(matching > 0, "Missing " + state + "/" + mode + " sample"); + } + + @Override + protected String getProfilerCommand() { + return "wall=1s,filter=,wallprecheck=true"; + } + + @Override + protected boolean isPlatformSupported() { + return !Platform.isJ9() && !Platform.isZing(); + } +} From 1690e26d07adfe212d82e11a3e9eb7aa5de625ad Mon Sep 17 00:00:00 2001 From: Paul Fournillon Date: Tue, 20 Oct 2026 18:37:34 +0200 Subject: [PATCH 5/6] perf: add benchmark for unowned wall-tail recording --- ddprof-lib/src/main/cpp/livenessTracker.cpp | 14 ++-- ddprof-lib/src/main/cpp/livenessTracker.h | 1 + .../src/test/cpp/livenessTracker_ut.cpp | 77 ++++++++++++++++++- ...iveHeapThenUnownedBlockedTailDumpTest.java | 31 ++++++++ 4 files changed, 116 insertions(+), 7 deletions(-) create mode 100644 ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java diff --git a/ddprof-lib/src/main/cpp/livenessTracker.cpp b/ddprof-lib/src/main/cpp/livenessTracker.cpp index 538854d9f6..d7e6f9cb46 100644 --- a/ddprof-lib/src/main/cpp/livenessTracker.cpp +++ b/ddprof-lib/src/main/cpp/livenessTracker.cpp @@ -2565,8 +2565,7 @@ void LivenessTracker::onGC() { } void LivenessTracker::getLiveTraceIds(CallTraceIdSet& out_buffer) { - out_buffer.clear(); - + // processTraces() clears the shared set before invoking all liveness checkers. if (!_enabled || !_initialized) { return; } @@ -2574,12 +2573,15 @@ void LivenessTracker::getLiveTraceIds(CallTraceIdSet& out_buffer) { // Lock the table to iterate over tracking entries _table_lock.lockShared(); - // Reserve space to avoid reallocations during filling - // Note: unordered_set uses rehash for capacity management - out_buffer.rehash(static_cast(_table_size / 0.75f)); + const int table_size = __atomic_load_n(&_table_size, __ATOMIC_ACQUIRE); + // Include IDs from earlier checkers without shrinking their reserved capacity. + const size_t capacity = out_buffer.size() + static_cast(table_size); + if (capacity > out_buffer.bucket_count() * out_buffer.max_load_factor()) { + out_buffer.reserve(capacity); + } // Collect call_trace_id values from all live tracking entries - for (int i = 0; i < _table_size; i++) { + for (int i = 0; i < table_size; i++) { TrackingEntry* entry = &_table[i]; // Skip unpublished slots (shared lock - see TrackingEntry::ready). if (__atomic_load_n(&entry->ready, __ATOMIC_ACQUIRE) != 1) { diff --git a/ddprof-lib/src/main/cpp/livenessTracker.h b/ddprof-lib/src/main/cpp/livenessTracker.h index 20afe41418..2a2a1b6c48 100644 --- a/ddprof-lib/src/main/cpp/livenessTracker.h +++ b/ddprof-lib/src/main/cpp/livenessTracker.h @@ -1655,6 +1655,7 @@ class alignas(alignof(SpinLock)) LivenessTracker { } private: + // Appends published live-object IDs to the shared dump-time preservation set. void getLiveTraceIds(CallTraceIdSet& out_buffer); }; diff --git a/ddprof-lib/src/test/cpp/livenessTracker_ut.cpp b/ddprof-lib/src/test/cpp/livenessTracker_ut.cpp index 5b6e10f90f..6bdcd98e1f 100644 --- a/ddprof-lib/src/test/cpp/livenessTracker_ut.cpp +++ b/ddprof-lib/src/test/cpp/livenessTracker_ut.cpp @@ -1090,9 +1090,27 @@ TEST_F(SelectLeakCandidatesTest, TopKlassesByGenerationCountEmptyTableReturnsZer // uses for heapFloorRising(), plus setMaxHeapBytesForTest() to avoid the // JNI-dependent HeapUsage::getMaxHeap() call this suite has no live JVM for. // --------------------------------------------------------------------------- -// Reaches the private state onGC()'s container-usage gate depends on. +// Reaches private state for GC and liveness-collection tests. class LivenessTrackerTestAccessor { public: + static void collectLiveTraceIdsForTest(LivenessTracker *t, bool enabled, + bool initialized, TrackingEntry *entries, + int count, CallTraceIdSet& ids) { + bool saved_enabled = t->_enabled; + bool saved_initialized = t->_initialized; + TrackingEntry *saved_table = t->_table; + int saved_size = t->_table_size; + t->_enabled = enabled; + t->_initialized = initialized; + t->_table = entries; + t->_table_size = count; + t->getLiveTraceIds(ids); + t->_enabled = saved_enabled; + t->_initialized = saved_initialized; + t->_table = saved_table; + t->_table_size = saved_size; + } + // Runs one onGC() with the given _container_limit_resolved value and returns the // container usage it recorded. Restores the touched fields afterwards. static u64 containerUsageRecordedByOnGC(LivenessTracker *t, bool limit_resolved) { @@ -1185,6 +1203,63 @@ class LivenessTrackerTestAccessor { } }; +TEST(LivenessTraceIdsTest, DisabledCheckerPreservesOtherCheckersIds) { + CallTraceIdSet ids{99}; + LivenessTrackerTestAccessor::collectLiveTraceIdsForTest( + LivenessTracker::instance(), false, true, nullptr, 0, ids); + EXPECT_EQ(1U, ids.size()); + EXPECT_EQ(1U, ids.count(99)); +} + +TEST(LivenessTraceIdsTest, UninitializedCheckerPreservesOtherCheckersIds) { + CallTraceIdSet ids{99}; + LivenessTrackerTestAccessor::collectLiveTraceIdsForTest( + LivenessTracker::instance(), true, false, nullptr, 0, ids); + EXPECT_EQ(1U, ids.size()); + EXPECT_EQ(1U, ids.count(99)); +} + +TEST(LivenessTraceIdsTest, AddsOnlyPublishedLiveIdsWithoutErasingOtherCheckersIds) { + TrackingEntry entries[4]{}; + entries[0].ready = 1; + entries[0].ref = reinterpret_cast(1); + entries[0].call_trace_id = 42; + entries[1].ref = reinterpret_cast(1); + entries[1].call_trace_id = 43; // Not published yet. + entries[2].ready = 1; + entries[2].call_trace_id = 44; // No live reference. + entries[3].ready = 1; + entries[3].ref = reinterpret_cast(1); + entries[3].call_trace_id = 42; // Duplicate live trace. + CallTraceIdSet ids{99}; + + LivenessTrackerTestAccessor::collectLiveTraceIdsForTest( + LivenessTracker::instance(), true, true, entries, 4, ids); + + EXPECT_EQ(2U, ids.size()); + EXPECT_EQ(1U, ids.count(99)); + EXPECT_EQ(1U, ids.count(42)); + EXPECT_EQ(0U, ids.count(43)); + EXPECT_EQ(0U, ids.count(44)); +} + +TEST(LivenessTraceIdsTest, PreservesPreallocatedCapacityForOtherCheckers) { + TrackingEntry entry{}; + entry.ready = 1; + entry.ref = reinterpret_cast(1); + entry.call_trace_id = 42; + CallTraceIdSet ids{99}; + ids.reserve(256); + size_t buckets = ids.bucket_count(); + + LivenessTrackerTestAccessor::collectLiveTraceIdsForTest( + LivenessTracker::instance(), true, true, &entry, 1, ids); + + EXPECT_EQ(1U, ids.count(99)); + EXPECT_EQ(1U, ids.count(42)); + EXPECT_GE(ids.bucket_count(), buckets); +} + TEST(LivenessTrackerSessionTest, ResetSessionClearsOnlyRecordingGates) { LivenessTracker *tracker = LivenessTracker::instance(); LivenessTrackerTestAccessor::setSessionGatesForTest( diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java new file mode 100644 index 0000000000..415a9d5da7 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java @@ -0,0 +1,31 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import java.nio.file.Files; +import java.nio.file.Path; +import org.junit.jupiter.api.Assumptions; + +/** Verifies wall-tail trace preservation after the live-heap liveness checker is registered. */ +public class LiveHeapThenUnownedBlockedTailDumpTest extends UnownedBlockedTailDumpTest { + /** + * Starts and stops a live-heap recording before each wall recording. Its liveness checker remains + * registered and must preserve IDs contributed by the wall-tail checker even with no live objects. + */ + @Override + protected void beforeProfilerStart() throws Exception { + Assumptions.assumeTrue(isDebugBuild(), "Requires the debug-only synchronous sampling driver"); + Path liveRecording = Files.createTempFile("live-heap-before-wall-tail-", ".jfr"); + try { + profiler.execute("start,memory=256:L,jfr,file=" + liveRecording.toAbsolutePath()); + } finally { + profiler.stop(); + if (!Boolean.getBoolean("ddprof_test.keep_jfrs")) { + Files.deleteIfExists(liveRecording); + } + } + } +} From 2a6d2d8eb7341c91c984e02b2134662c4795ebf0 Mon Sep 17 00:00:00 2001 From: Paul Fournillon Date: Wed, 21 Oct 2026 14:46:06 +0200 Subject: [PATCH 6/6] fix: remove JVMTI unowned taskblock suppression --- ddprof-lib/src/main/cpp/wallClock.cpp | 36 +++++--- ddprof-lib/src/main/cpp/wallClock.h | 7 ++ .../src/test/cpp/wallClockBlockRestart_ut.cpp | 23 ++++- ddprof-lib/src/test/cpp/wallClock_ut.cpp | 86 +++++++++++++++++++ .../wallclock/JvmtiBasedPrecheckTest.java | 6 ++ ...iveHeapThenUnownedBlockedTailDumpTest.java | 9 +- .../profiler/wallclock/PrecheckTest.java | 68 ++++++++------- 7 files changed, 190 insertions(+), 45 deletions(-) diff --git a/ddprof-lib/src/main/cpp/wallClock.cpp b/ddprof-lib/src/main/cpp/wallClock.cpp index 859607a5cd..0cd5e02e97 100644 --- a/ddprof-lib/src/main/cpp/wallClock.cpp +++ b/ddprof-lib/src/main/cpp/wallClock.cpp @@ -84,8 +84,8 @@ bool BaseWallClock::suppressAlreadySampled(const ThreadEntry& entry) { } static inline WallPrecheckResult prepareWallPrecheck( - ProfiledThread* current, bool precheck -#ifdef DEBUG + ProfiledThread* current, bool precheck, bool unowned_fallback +#if defined(DEBUG) || defined(UNIT_TEST) , OSThreadState observed_state_for_test = OSThreadState::UNKNOWN #endif ) { @@ -132,11 +132,13 @@ static inline WallPrecheckResult prepareWallPrecheck( result.owned_block_generation = block_generation; return result; } - if (!block_slot->unownedBlockedFallbackEnabled()) { + // Delegated samples have no reusable local trace ID for replaying a weighted + // tail. Bypass only the unowned fallback when the engine cannot emit it. + if (!unowned_fallback || !block_slot->unownedBlockedFallbackEnabled()) { return result; } -#ifdef DEBUG +#if defined(DEBUG) || defined(UNIT_TEST) result.observed_state = observed_state_for_test != OSThreadState::UNKNOWN ? observed_state_for_test : getOSThreadState(); #else @@ -173,6 +175,18 @@ static inline void finishWallPrecheck(const WallPrecheckResult& precheck, } } +#ifdef UNIT_TEST +bool BaseWallClock::wallPrecheckForTest( + ProfiledThread* current, bool unowned_fallback, OSThreadState observed_state, + u64& weight, bool recorded) { + WallPrecheckResult result = + prepareWallPrecheck(current, true, unowned_fallback, observed_state); + weight = result.unowned_weight; + finishWallPrecheck(result, recorded); + return result.suppress; +} +#endif + static inline void emitUnownedBlockedTailForWallPrecheck( int tid, const WallPrecheckResult& precheck) { if (!precheck.flush_unowned_tail || precheck.flush_call_trace_id == 0) { @@ -245,14 +259,14 @@ bool BaseWallClock::recordUnownedWallTailAcrossDumpForTest( ExecutionEvent event; event._thread_state = OSThreadState::SLEEPING; event._execution_mode = ExecutionMode::JAVA; - WallPrecheckResult first = prepareWallPrecheck(current, true, OSThreadState::SLEEPING); + WallPrecheckResult first = prepareWallPrecheck(current, true, true, OSThreadState::SLEEPING); if (first.suppress || first.unowned_weight_slot != slot) return false; if (!recordAsgctWallSample(nullptr, 1, current->tid(), 0, &event, first, &dump_test) || dump_test.error) return false; // One further blocked observation contributes exactly one pending unit. - if (!prepareWallPrecheck(current, true, OSThreadState::SLEEPING).suppress) return false; - WallPrecheckResult tail = prepareWallPrecheck(current, true, OSThreadState::RUNNABLE); + if (!prepareWallPrecheck(current, true, true, OSThreadState::SLEEPING).suppress) return false; + WallPrecheckResult tail = prepareWallPrecheck(current, true, true, OSThreadState::RUNNABLE); if (!tail.flush_unowned_tail || tail.flush_weight != 1) return false; event._thread_state = OSThreadState::RUNNABLE; return recordAsgctWallSample(nullptr, 1, current->tid(), 0, &event, tail, &dump_test) && @@ -335,7 +349,7 @@ void WallClockASGCT::signalHandler(int signo, siginfo_t *siginfo, void *ucontext // its first successful MethodSample and suppresses subsequent signals. // Unowned blocked observations use weighted fallback sampling because raw OS // state cannot distinguish one long sleep from several shorter runs. - WallPrecheckResult precheck = prepareWallPrecheck(current, _precheck); + WallPrecheckResult precheck = prepareWallPrecheck(current, _precheck, true); if (precheck.suppress) { return; } @@ -582,7 +596,7 @@ void WallClockJvmti::signalHandler(int signo, siginfo_t *siginfo, return; } - WallPrecheckResult precheck = prepareWallPrecheck(current, _precheck); + WallPrecheckResult precheck = prepareWallPrecheck(current, _precheck, false); if (precheck.suppress) { return; } @@ -608,8 +622,8 @@ void WallClockJvmti::signalHandler(int signo, siginfo_t *siginfo, // Pass nullptr ucontext so the JVM uses safepoint-based stack walking. // Passing the signal-frame PC causes the extension to reject samples where // the thread is currently inside JVM-internal (non-Java) code. - // JVMTI-delegated samples carry a correlation_id, not a call_trace_id, so - // unowned tail flushing remains limited to the ASGCT wall engine. + // Unowned observations retain unit weight: this engine cannot replay a + // cached blocked stack to account for suppressed tail observations. bool recorded = Profiler::instance()->recordSampleDelegated( nullptr, last_sample, tid, BCI_WALL, &event); finishWallPrecheck(precheck, recorded); diff --git a/ddprof-lib/src/main/cpp/wallClock.h b/ddprof-lib/src/main/cpp/wallClock.h index 1f11c31f3a..3763a15baf 100644 --- a/ddprof-lib/src/main/cpp/wallClock.h +++ b/ddprof-lib/src/main/cpp/wallClock.h @@ -239,6 +239,13 @@ class BaseWallClock : public Engine { static std::atomic _force_start_failure_for_test; public: #endif +#ifdef UNIT_TEST + // Exercises precheck decisions and successful/failed recording completion + // with controlled thread states, without a JVM or signal delivery. + static bool wallPrecheckForTest( + ProfiledThread* current, bool unowned_fallback, OSThreadState observed_state, + u64& weight, bool recorded = false); +#endif #ifdef DEBUG // Drives the real precheck/recording path with controlled OS-state inputs // and an intervening JFR dump. Called synchronously from the JNI test hook. diff --git a/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp b/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp index fcc623c5c9..0eb1f468df 100644 --- a/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp +++ b/ddprof-lib/src/test/cpp/wallClockBlockRestart_ut.cpp @@ -207,8 +207,11 @@ TEST_P(WallClockBlockRestartTest, SurvivingOwnerRefreshesOnlyRecordingState) { TEST_P(WallClockBlockRestartTest, ThreadExitWhileStoppedRetiresIdentity) { AdmissionPause pause; + // Make the caller register again rather than refresh a retained identity. + registry->unregisterThreadByTid(current->tid()); int worker_tid = -1; int worker_slot = -1; + u64 worker_lifecycle_generation = 0; u64 token = 0; std::thread worker([&] { auto* self = ProfiledThread::initCurrentThreadSignalSafe(); @@ -216,6 +219,7 @@ TEST_P(WallClockBlockRestartTest, ThreadExitWhileStoppedRetiresIdentity) { worker_tid = self->tid(); token = enterHook(); worker_slot = self->filterSlotId(); + worker_lifecycle_generation = registry->slotForId(worker_slot)->lifecycleGeneration(); AdmissionPause::pause(&pause); // No ThreadEnd callback or explicit unregister: pthread teardown must // retire this identity while registry admission is disabled. @@ -236,6 +240,10 @@ TEST_P(WallClockBlockRestartTest, ThreadExitWhileStoppedRetiresIdentity) { ASSERT_TRUE(reached); ASSERT_NE(0u, token); EXPECT_EQ(nullptr, registry->lookupByTid(worker_tid)); + auto* retired_identity = registry->slotForId(worker_slot); + ASSERT_NE(nullptr, retired_identity); + EXPECT_EQ(-1, retired_identity->nativeTid()); + EXPECT_EQ(0u, retired_identity->recordingEpoch()); auto* block = tracker->slotForId(worker_slot); ASSERT_NE(nullptr, block); EXPECT_EQ(BlockRunOwner::NONE, block->activeBlockOwner()); @@ -244,7 +252,18 @@ TEST_P(WallClockBlockRestartTest, ThreadExitWhileStoppedRetiresIdentity) { registry->init("", true); u64 new_token = enterHook(); ASSERT_NE(0u, new_token); - EXPECT_NE(nullptr, registry->activeSlotForId(current->filterSlotId(), current->tid())); - EXPECT_NE(token, new_token); + auto* new_identity = registry->activeSlotForId(current->filterSlotId(), current->tid()); + ASSERT_NE(nullptr, new_identity); + EXPECT_EQ(current->tid(), new_identity->nativeTid()); + // popFromFreeList() starts at a shard selected by the calling thread's ID, + // so the caller may receive another free slot. Lifecycle counters belong + // to individual slots and can only be compared when the slot is reused. + if (current->filterSlotId() == worker_slot) { + EXPECT_GT(new_identity->lifecycleGeneration(), worker_lifecycle_generation); + } + auto* new_block = tracker->slotForId(current->filterSlotId()); + ASSERT_NE(nullptr, new_block); + EXPECT_EQ(BlockRunOwner::JAVA, new_block->activeBlockOwner()); + EXPECT_EQ(hookState(), new_block->activeBlockState()); exitHook(new_token); } diff --git a/ddprof-lib/src/test/cpp/wallClock_ut.cpp b/ddprof-lib/src/test/cpp/wallClock_ut.cpp index 3b90a4caa0..9307322a6d 100644 --- a/ddprof-lib/src/test/cpp/wallClock_ut.cpp +++ b/ddprof-lib/src/test/cpp/wallClock_ut.cpp @@ -9,8 +9,12 @@ #include #include #include "arguments.h" +#include "counters.h" +#include "profiler.h" #include "wallClock.h" +#include + // profiler.cpp's Profiler::start() falls back to ThreadFilter::deactivateRecording() // when the wall engine fails to start. This proves BaseWallClock::start() can // genuinely return a non-OK Error, i.e. that the fallback's trigger condition @@ -195,3 +199,85 @@ TEST_F(WallClockCapacityTest, ExhaustionKeepsSendingSignalsAcrossRecordings) { registry.init("", true); } } + +class WallClockPrecheckTest : public ::testing::Test { +protected: + static constexpr int kTid = 12345; + Profiler* profiler = Profiler::instance(); + ThreadFilter* filter = profiler->threadFilter(); + WallClockBlockTracker* tracker = profiler->blockTracker(); + std::unique_ptr current{ + nullptr, ProfiledThread::deleteForTest}; + ThreadFilter::SlotID slot_id = -1; + + void SetUp() override { + Counters::reset(); + filter->init("", true); + slot_id = filter->registerThread(kTid); + ASSERT_GE(slot_id, 0); + current.reset(ProfiledThread::forTid(kTid)); + current->setFilterSlotId(slot_id); + } + + void TearDown() override { + tracker->resetAll(); + filter->deactivateRecording(); + current.reset(); + Counters::reset(); + } +}; + +TEST_F(WallClockPrecheckTest, UnownedObservationsRetainUnitWeightWithoutFallback) { + // Repeated short blocked bursts used to lose their suppressed remainder + // on every runnable observation in the delegated JVMTI path. + for (int burst = 0; burst < 3; ++burst) { + for (int observation = 0; observation < 7; ++observation) { + OSThreadState state = observation < 6 ? OSThreadState::SLEEPING + : OSThreadState::RUNNABLE; + u64 weight = 0; + EXPECT_FALSE(BaseWallClock::wallPrecheckForTest( + current.get(), false, state, weight, true)); + EXPECT_EQ(1ULL, weight); + } + } + EXPECT_EQ(0ULL, tracker->slotForId(slot_id)->unowned_blocked_pending_weight.load()); + EXPECT_EQ(0, Counters::getCounter(WC_UNOWNED_BLOCKED_SUPPRESSED)); + EXPECT_EQ(0, Counters::getCounter(WC_UNOWNED_BLOCKED_RECORDED)); +} + +TEST_F(WallClockPrecheckTest, OwnedBlocksStillSuppressWithoutUnownedFallback) { + u64 token = tracker->enterBlockedRun( + filter, slot_id, OSThreadState::SLEEPING, BlockRunOwner::TASK_BLOCK); + ASSERT_NE(0ULL, token); + u64 weight = 0; + + // A failed write must leave the owned run eligible for another attempt. + EXPECT_FALSE(BaseWallClock::wallPrecheckForTest( + current.get(), false, OSThreadState::SLEEPING, weight, false)); + EXPECT_FALSE(BaseWallClock::wallPrecheckForTest( + current.get(), false, OSThreadState::SLEEPING, weight, true)); + EXPECT_TRUE(BaseWallClock::wallPrecheckForTest( + current.get(), false, OSThreadState::SLEEPING, weight)); + EXPECT_EQ(1, Counters::getCounter(WC_SIGNAL_SUPPRESSED_OWNED_BLOCK)); + + ASSERT_TRUE(tracker->exitBlockedRun( + slot_id, WallClockBlockTracker::tokenGeneration(token))); + EXPECT_FALSE(BaseWallClock::wallPrecheckForTest( + current.get(), false, OSThreadState::SLEEPING, weight, true)); + EXPECT_EQ(1ULL, weight); +} + +TEST_F(WallClockPrecheckTest, UnownedFallbackStillAccumulatesWeightWhenEnabled) { + u64 weight = 0; + EXPECT_FALSE(BaseWallClock::wallPrecheckForTest( + current.get(), true, OSThreadState::SLEEPING, weight, true)); + EXPECT_EQ(1ULL, weight); + for (int observation = 0; observation < 9; ++observation) { + EXPECT_TRUE(BaseWallClock::wallPrecheckForTest( + current.get(), true, OSThreadState::SLEEPING, weight)); + } + EXPECT_FALSE(BaseWallClock::wallPrecheckForTest( + current.get(), true, OSThreadState::SLEEPING, weight, true)); + EXPECT_EQ(10ULL, weight); + EXPECT_EQ(9, Counters::getCounter(WC_UNOWNED_BLOCKED_SUPPRESSED)); +} diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java index 07ae6de492..9f8d7030c9 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JvmtiBasedPrecheckTest.java @@ -61,4 +61,10 @@ protected String getProfilerCommand() { protected String getPrecheckDisabledProfilerCommand() { return "wall=1ms,filter=,wallprecheck=false,jvmtistacks=true"; } + + /** Delegated stacks cannot replay weighted tails through a local call-trace ID. */ + @Override + protected boolean usesWeightedUnownedFallback() { + return false; + } } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java index 415a9d5da7..18ae98eb08 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/LiveHeapThenUnownedBlockedTailDumpTest.java @@ -5,12 +5,19 @@ package com.datadoghq.profiler.wallclock; +import com.datadoghq.profiler.Platform; import java.nio.file.Files; import java.nio.file.Path; import org.junit.jupiter.api.Assumptions; /** Verifies wall-tail trace preservation after the live-heap liveness checker is registered. */ public class LiveHeapThenUnownedBlockedTailDumpTest extends UnownedBlockedTailDumpTest { + /** Requires a JVM that supports live-heap allocation sampling. */ + @Override + protected boolean isPlatformSupported() { + return super.isPlatformSupported() && Platform.isJavaVersionAtLeast(11); + } + /** * Starts and stops a live-heap recording before each wall recording. Its liveness checker remains * registered and must preserve IDs contributed by the wall-tail checker even with no live objects. @@ -21,8 +28,8 @@ protected void beforeProfilerStart() throws Exception { Path liveRecording = Files.createTempFile("live-heap-before-wall-tail-", ".jfr"); try { profiler.execute("start,memory=256:L,jfr,file=" + liveRecording.toAbsolutePath()); - } finally { profiler.stop(); + } finally { if (!Boolean.getBoolean("ddprof_test.keep_jfrs")) { Files.deleteIfExists(liveRecording); } diff --git a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java index c109a50d23..0a4d2191f3 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/PrecheckTest.java @@ -134,18 +134,13 @@ public void unownedSleepingThreadIsNotExactOncePerRunSuppressed() throws Excepti Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); leaveClearedInitializedContext(); + registerOutsideContextWindow(); + Thread.sleep(300); stopProfiler(); - long sampleCount = samplesForThread(Thread.currentThread().getName()); - assertTrue(sampleCount > 0, - "Unowned Thread.sleep must remain sampled; got: " + sampleCount); - Map counters = profiler.getDebugCounters(); - assertTrue(counters.getOrDefault("wc_unowned_blocked_recorded", 0L) > 0, - "Expected the weighted unowned-block fallback to record samples"); - assertTrue(counters.getOrDefault("wc_unowned_blocked_suppressed", 0L) > 0, - "Expected the weighted unowned-block fallback to suppress intermediate samples"); + assertUnownedSamples(Thread.currentThread().getName()); } @Test @@ -154,6 +149,7 @@ public void unownedSleepingTailWeightIsPreserved() throws Exception { Assumptions.assumeTrue(Platform.isJavaVersionAtLeast(11)); Thread sleeper = new Thread(() -> { + registerOutsideContextWindow(); try { for (int i = 0; i < TAIL_WEIGHT_ITERATIONS; i++) { Thread.sleep(TAIL_WEIGHT_SLEEP_MILLIS); @@ -172,16 +168,7 @@ public void unownedSleepingTailWeightIsPreserved() throws Exception { stopProfiler(); - WeightedSamples weightedSamples = weightedSamplesForThread(TAIL_WEIGHT_THREAD); - assertTrue(weightedSamples.count > 0, - "Expected MethodSample events for " + TAIL_WEIGHT_THREAD); - assertTrue(weightedSamples.weight > weightedSamples.count, - "Expected preserved suppressed tail weight for " + TAIL_WEIGHT_THREAD - + ", count=" + weightedSamples.count - + ", weight=" + weightedSamples.weight); - assertTrue(profiler.getDebugCounters() - .getOrDefault("wc_unowned_blocked_suppressed", 0L) > 0, - "Expected unowned blocked samples to be suppressed and represented by weight"); + assertUnownedSamples(TAIL_WEIGHT_THREAD); } @Test @@ -251,13 +238,19 @@ private void leaveClearedInitializedContext() { profiler.clearTraceContext(); } + /** Registers the calling thread lazily, then leaves its sleep outside the context window. */ + private void registerOutsideContextWindow() { + profiler.addThread(); + profiler.removeThread(); + } + @Override protected String getProfilerCommand() { // This suite verifies sampling and suppression for threads outside a // tracing-context window. Owned-block suppression only applies to the // unfiltered wall-clock scope (explicit empty filter=), and only while - // the thread stays outside the context window, so threads must not - // call addThread(). + // the thread stays outside the context window. Threads that register + // through addThread() must call removeThread() before the sampled workload. return "wall=1ms,filter=,wallprecheck=true"; } @@ -265,6 +258,11 @@ protected String getPrecheckDisabledProfilerCommand() { return "wall=1ms,filter=,wallprecheck=false"; } + /** Returns whether the engine can replay unowned blocked samples with a cached stack. */ + protected boolean usesWeightedUnownedFallback() { + return true; + } + private long samplesForThread(String threadName) { long count = 0; JfrEvents events = verifyEvents("datadog.MethodSample", false); @@ -276,7 +274,8 @@ private long samplesForThread(String threadName) { return count; } - private WeightedSamples weightedSamplesForThread(String threadName) { + /** Verifies weighted ASGCT fallback or ordinary delegated sampling for the named thread. */ + private void assertUnownedSamples(String threadName) { long count = 0; long weight = 0; JfrEvents events = verifyEvents("datadog.MethodSample", false); @@ -284,18 +283,25 @@ private WeightedSamples weightedSamplesForThread(String threadName) { if (threadName.equals(item.getThreadName("eventThread"))) { count++; weight += item.getLong(WEIGHT, 0); + if (!usesWeightedUnownedFallback()) { + assertEquals(1L, item.getLong(WEIGHT, 0), + "Delegated unowned samples must retain unit weight"); + } } } - return new WeightedSamples(count, weight); - } - - private static final class WeightedSamples { - final long count; - final long weight; - - WeightedSamples(long count, long weight) { - this.count = count; - this.weight = weight; + assertTrue(count > 0, "Expected MethodSample events for " + threadName); + Map counters = profiler.getDebugCounters(); + long suppressed = counters.getOrDefault("wc_unowned_blocked_suppressed", 0L); + long recorded = counters.getOrDefault("wc_unowned_blocked_recorded", 0L); + if (usesWeightedUnownedFallback()) { + assertTrue(weight > count, + "Expected suppressed observations to be represented by weight for " + threadName + + ", count=" + count + ", weight=" + weight); + assertTrue(recorded > 0, "Expected weighted unowned-block fallback samples"); + assertTrue(suppressed > 0, "Expected weighted unowned-block fallback suppression"); + } else { + assertEquals(0L, suppressed, "Delegated unowned observations must remain sampled"); + assertEquals(0L, recorded, "Delegated samples must bypass the weighted fallback"); } } }