diff --git a/ddprof-lib/src/main/cpp/counters.h b/ddprof-lib/src/main/cpp/counters.h index ef8bf8a441..e55fc3a50b 100644 --- a/ddprof-lib/src/main/cpp/counters.h +++ b/ddprof-lib/src/main/cpp/counters.h @@ -71,13 +71,19 @@ 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_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(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 67ff97b381..ece568fd14 100644 --- a/ddprof-lib/src/main/cpp/event.h +++ b/ddprof-lib/src/main/cpp/event.h @@ -58,7 +58,7 @@ class ExecutionEvent : public Event { OSThreadState _thread_state; ExecutionMode _execution_mode; u64 _weight; - u32 _call_trace_id; + u64 _call_trace_id; ExecutionEvent() : Event(), _thread_state(OSThreadState::RUNNABLE), _execution_mode(ExecutionMode::UNKNOWN), @@ -123,13 +123,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; } @@ -168,10 +168,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; } } @@ -182,7 +182,7 @@ class WallClockEpochEvent { void newEpoch(u64 start_time) { _dirty = false; _start_time = start_time; - _num_suppressed_sampled_run = 0; + _num_suppressed_owned_block = 0; } }; @@ -207,4 +207,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 1bcd475d36..da8cb46fee 100644 --- a/ddprof-lib/src/main/cpp/flightRecorder.cpp +++ b/ddprof-lib/src/main/cpp/flightRecorder.cpp @@ -1945,6 +1945,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); @@ -1955,7 +1970,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); } @@ -2218,6 +2233,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 ee6929b4f1..a266f7f51b 100644 --- a/ddprof-lib/src/main/cpp/flightRecorder.h +++ b/ddprof-lib/src/main/cpp/flightRecorder.h @@ -319,6 +319,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, @@ -427,6 +428,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 a7be9f44b7..131b0ad46b 100644 --- a/ddprof-lib/src/main/cpp/javaApi.cpp +++ b/ddprof-lib/src/main/cpp/javaApi.cpp @@ -32,6 +32,7 @@ #include "otel_process_ctx.h" #include "profiler.h" #include "threadLocalData.h" +#include "taskBlockRecorder.h" #include "tsc.h" #include "vmEntry.h" #include @@ -417,14 +418,16 @@ Java_com_datadoghq_profiler_JavaProfiler_blockEnter0( if (current == nullptr) { return 0; } - ThreadFilter *tf = Profiler::instance()->threadFilter(); - if (!tf->registryActive()) { + if (ContextApi::snapshot().spanId != 0) { return 0; } - ThreadFilter::SlotID slot_id = ensureCurrentThreadFilterSlot(tf, current); - if (slot_id < 0) { + Profiler *profiler = Profiler::instance(); + ThreadFilter *tf = profiler->threadFilter(); + if (!profiler->taskBlockEnabled() && !tf->enabled()) { return 0; } + ThreadFilter::SlotID slot_id = ensureCurrentThreadFilterSlot(tf, current); + if (slot_id < 0) return 0; return static_cast(tf->enterBlockedRun(slot_id, decoded)); } @@ -450,6 +453,60 @@ Java_com_datadoghq_profiler_JavaProfiler_blockExit0( } } +extern "C" DLLEXPORT jlong JNICALL +Java_com_datadoghq_profiler_JavaProfiler_beginTaskBlock0( + JNIEnv *env, jclass unused, jthread thread) { + if (!JVMSupport::isPlatformThread(env, thread)) { + return 0; + } + 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; + ThreadFilter::SlotID slot_id = ensureCurrentThreadFilterSlot(tf, current); + if (slot_id < 0) return 0; + + Context context = ContextApi::snapshot(); + if (context.spanId != 0) { + Counters::increment(TASK_BLOCK_SKIPPED_TRACE_CONTEXT); + return 0; + } + u64 token = tf->enterBlockedRun( + slot_id, OSThreadState::SLEEPING, BlockRunOwner::JAVA); + if (!current->taskBlockEnter(token, TSC::ticks(), context)) { + if (token != 0) { + tf->exitBlockedRun(slot_id, ThreadFilter::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 (!ThreadFilter::decodeBlockRunToken(block_token, slot_id, generation) || + !JVMSupport::isPlatformThread(env, thread)) { + return JNI_FALSE; + } + ProfiledThread *current = ProfiledThread::initCurrentThreadSignalSafe(); + if (current == nullptr) return JNI_FALSE; + + bool recorded = recordTaskBlockAtExit( + current, Profiler::instance()->threadFilter(), thread, 1, block_token, + slot_id, generation, 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 33496bb1bc..51632663e1 100644 --- a/ddprof-lib/src/main/cpp/jfrMetadata.cpp +++ b/ddprof-lib/src/main/cpp/jfrMetadata.cpp @@ -156,8 +156,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") @@ -209,6 +209,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 ac241a7a84..f5102ef705 100644 --- a/ddprof-lib/src/main/cpp/jfrMetadata.h +++ b/ddprof-lib/src/main/cpp/jfrMetadata.h @@ -81,6 +81,7 @@ enum JfrType { T_UNWIND_FAILURE = 126, T_MALLOC = 127, T_NATIVE_SOCKET = 128, + T_TASK_BLOCK = 129, 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 783c34e458..86dff230ce 100644 --- a/ddprof-lib/src/main/cpp/jvmSupport.cpp +++ b/ddprof-lib/src/main/cpp/jvmSupport.cpp @@ -16,16 +16,38 @@ #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; + + 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 f3d664d2dc..4d8f7c4781 100644 --- a/ddprof-lib/src/main/cpp/jvmSupport.h +++ b/ddprof-lib/src/main/cpp/jvmSupport.h @@ -44,6 +44,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 070cb32f7d..2ea7fe8b23 100644 --- a/ddprof-lib/src/main/cpp/profiler.cpp +++ b/ddprof-lib/src/main/cpp/profiler.cpp @@ -35,6 +35,7 @@ #include "stackFrame.h" #include "stackWalker.h" #include "symbols.h" +#include "taskBlockRecorder.h" #include "tsc.h" #include "utils.h" #include "wallClock.h" @@ -47,6 +48,7 @@ #include #include #include +#include #include #include #include @@ -151,6 +153,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); @@ -158,6 +162,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) { @@ -770,6 +779,92 @@ 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]; + ASGCT_CallFrame *frames = buffer->_asgct_frames; + jvmtiFrameInfo *jvmti_frames = buffer->_jvmti_frames; + jint num_frames = 0; +#ifdef COUNTERS + u64 stack_start = TSC::ticks(); +#endif + jvmtiError error = VM::jvmti()->GetStackTrace( + thread, start_depth, _max_stack_depth, jvmti_frames, &num_frames); + if (error != JVMTI_ERROR_NONE || num_frames <= 0) { + _locks[lock_index].unlock(); + return TaskBlockRecordResult::STACK_CAPTURE_FAILED; + } + + copyJvmtiFrames(frames, jvmti_frames, num_frames); + u64 call_trace_id = + _call_trace_storage.put(num_frames, 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); +} + +void Profiler::beginTaskBlockRotation() { + _task_block_rotation.store(true, std::memory_order_release); + while (_task_block_inflight.load(std::memory_order_acquire) != 0) { + std::this_thread::yield(); + } +} + +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) { @@ -1332,6 +1427,7 @@ Error Profiler::start(Arguments &args, bool reset) { if (error) { return error; } + _task_block_enabled.store(false, std::memory_order_release); // Force libgcc_s to load now (idempotent dlopen) so the JVM's DWARF // unwinder cannot lazy-load it later from signal context. @@ -1543,6 +1639,7 @@ Error Profiler::start(Arguments &args, bool reset) { _libs->stopRefresher(); return error; } + initializeTaskBlockDurationThreshold(); int activated = 0; if ((_event_mask & EM_CPU) && _cpu_engine != &noop_engine) { @@ -1636,6 +1733,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); @@ -1660,6 +1760,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 @@ -1677,6 +1778,11 @@ 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. + beginTaskBlockRotation(); + if (_event_mask & EM_ALLOC) _alloc_engine->stop(); if (_event_mask & EM_NATIVEMEM) @@ -1748,6 +1854,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 @@ -1841,10 +1948,12 @@ Error Profiler::dump(const char *path, const int length) { // its own writer/reader coordination; #527's classMapSharedGuard readers // (deferred vtable receiver resolution) are coordinated through // _class_map_lock. + beginTaskBlockRotation(); rotateDictsAndRun([&]{ err = _jfr.dump(path, length); __atomic_add_fetch(&_epoch, 1, __ATOMIC_SEQ_CST); }); + endTaskBlockRotation(); _thread_info.clearAll(thread_ids); _thread_info.reportCounters(); diff --git a/ddprof-lib/src/main/cpp/profiler.h b/ddprof-lib/src/main/cpp/profiler.h index 877ed7f2b5..e973bee9ea 100644 --- a/ddprof-lib/src/main/cpp/profiler.h +++ b/ddprof-lib/src/main/cpp/profiler.h @@ -132,6 +132,9 @@ class alignas(alignof(SpinLock)) Profiler { alignas(DEFAULT_CACHE_LINE_SIZE) volatile u64 _sample_seq; alignas(DEFAULT_CACHE_LINE_SIZE) u64 _failures[ASGCT_FAILURE_TYPES]; bool _wall_precheck = false; + std::atomic _task_block_enabled{false}; + std::atomic _task_block_rotation{false}; + std::atomic _task_block_inflight{0}; SpinLock _class_map_lock; SpinLock _locks[CONCURRENCY_LEVEL]; @@ -178,6 +181,8 @@ class alignas(alignof(SpinLock)) Profiler { void lockAll(); void unlockAll(); + void beginTaskBlockRotation(); + void endTaskBlockRotation(); // Rotate all three dictionaries, then run jfr_op under lockAll(). // @@ -447,6 +452,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, @@ -467,6 +491,15 @@ class alignas(alignof(SpinLock)) Profiler { static void unregisterThread(int tid); #ifdef UNIT_TEST + void beginTaskBlockRotationForTest() { 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..34492f2054 --- /dev/null +++ b/ddprof-lib/src/main/cpp/taskBlockRecorder.cpp @@ -0,0 +1,85 @@ +/* + * 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, + jthread thread, int start_depth, u64 block_token, + ThreadFilter::SlotID slot_id, u64 generation, + u64 blocker, u64 unblocking_span_id) { + u64 start_ticks = 0; + Context context{}; + if (!current->taskBlockExit(block_token, start_ticks, context)) { + return false; + } + + if (slot_id != ThreadFilter::tokenSlotId(block_token) || + generation != ThreadFilter::tokenGeneration(block_token)) { + return false; + } + + return finishTaskBlockAtExit( + current, thread_filter, thread, start_depth, block_token, start_ticks, + context, blocker, unblocking_span_id); +} + +bool finishTaskBlockAtExit(ProfiledThread* current, + ThreadFilter* thread_filter, 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(); + bool activity = profiler->tryEnterTaskBlockActivity(); + + ThreadFilter::SlotID slot_id = ThreadFilter::tokenSlotId(block_token); + u64 generation = ThreadFilter::tokenGeneration(block_token); + ThreadFilter::SlotID current_slot = current->filterSlotId(); + if (current_slot < 0) { + current_slot = thread_filter->slotIdByTid(current->tid()); + } + BlockRunSnapshot snapshot; + bool exited = current_slot == slot_id && + thread_filter->snapshotAndExitBlockedRun(slot_id, generation, &snapshot); + + if (!activity) { + Counters::increment(TASK_BLOCK_DROPPED_ROTATION); + return false; + } + if (!recording_enabled || !exited) { + profiler->leaveTaskBlockActivity(); + return false; + } + if (!snapshot.context_eligible) { + Counters::increment(TASK_BLOCK_SKIPPED_TRACE_CONTEXT); + profiler->leaveTaskBlockActivity(); + return false; + } + + bool recorded = recordTaskBlockIfEligible( + current->tid(), thread, start_depth, start_ticks, TSC::ticks(), context, + blocker, unblocking_span_id, snapshot.active_state, true); + profiler->leaveTaskBlockActivity(); + return recorded; +} diff --git a/ddprof-lib/src/main/cpp/taskBlockRecorder.h b/ddprof-lib/src/main/cpp/taskBlockRecorder.h new file mode 100644 index 0000000000..fb11a6155b --- /dev/null +++ b/ddprof-lib/src/main/cpp/taskBlockRecorder.h @@ -0,0 +1,97 @@ +/* + * 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, + jthread thread, int start_depth, u64 block_token, + ThreadFilter::SlotID slot_id, u64 generation, + u64 blocker, u64 unblocking_span_id); + +// Completes ThreadFilter 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, 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 c38b9b30ee..ad9e31ea54 100644 --- a/ddprof-lib/src/main/cpp/threadFilter.cpp +++ b/ddprof-lib/src/main/cpp/threadFilter.cpp @@ -34,6 +34,15 @@ ThreadFilter::ShardHead ThreadFilter::_free_heads[ThreadFilter::kShardCount] {}; +#ifdef UNIT_TEST +std::atomic + ThreadFilter::_block_run_publish_observer{nullptr}; + +void ThreadFilter::setBlockRunPublishObserverForTest(BlockRunPublishObserver observer) { + _block_run_publish_observer.store(observer, std::memory_order_release); +} +#endif + ThreadFilter::ThreadFilter() : _enabled(false), _registry_active(false), _track_unfiltered_wall(false) { // Initialize chunk pointers to null (lazy allocation) @@ -106,6 +115,7 @@ void ThreadFilter::initializeChunk(int chunk_idx) { slot.recording_epoch.store(0, std::memory_order_relaxed); slot.context_window_state.store(0, std::memory_order_relaxed); slot.active_block_state.store(OSThreadState::UNKNOWN, std::memory_order_relaxed); + slot.unowned_blocked_fallback_enabled.store(1, std::memory_order_relaxed); } // Try to install it atomically @@ -145,6 +155,7 @@ ThreadFilter::SlotID ThreadFilter::registerThread(int tid) { slot->lifecycle_generation.fetch_add(1, std::memory_order_acq_rel); slot->recording_epoch.store(0, std::memory_order_relaxed); slot->context_window_state.store(0, std::memory_order_relaxed); + slot->enableUnownedBlockedFallback(); slot->clearActiveBlockRun(OSThreadState::UNKNOWN); slot->tid.store(tid, std::memory_order_release); if (tid >= 0 && !indexSlot(reused_slot, tid)) { @@ -191,6 +202,7 @@ ThreadFilter::SlotID ThreadFilter::registerThread(int tid) { slot->lifecycle_generation.fetch_add(1, std::memory_order_acq_rel); slot->recording_epoch.store(0, std::memory_order_relaxed); slot->context_window_state.store(0, std::memory_order_relaxed); + slot->enableUnownedBlockedFallback(); slot->clearActiveBlockRun(OSThreadState::UNKNOWN); slot->tid.store(tid, std::memory_order_release); if (tid >= 0 && !indexSlot(index, tid)) { @@ -215,6 +227,7 @@ void ThreadFilter::refreshSlotForRecording(Slot* slot, RecordingEpoch epoch) { // payload, then publish the new epoch only after the reset is complete. slot->recording_epoch.store(0, std::memory_order_release); slot->context_window_state.store(0, std::memory_order_relaxed); + slot->enableUnownedBlockedFallback(); slot->clearActiveBlockRun(OSThreadState::UNKNOWN); slot->recording_epoch.store(epoch, std::memory_order_release); } @@ -306,6 +319,45 @@ ThreadFilter::Slot* ThreadFilter::activeSlotForId(SlotID slot_id, return slot; } +bool ThreadFilter::lookupThreadEntry(ThreadEntry& entry, + RecordingEpoch epoch) const { + Slot* slot = epoch != 0 ? lookupByTid(entry.tid, epoch) + : lookupByTid(entry.tid); + if (slot == nullptr) { + return false; + } + entry.slot = slot; + entry.lifecycle_generation = slot->lifecycleGeneration(); + entry.recording_epoch = slot->recordingEpoch(); + return true; +} + +ThreadFilter::SlotID ThreadFilter::ensureCurrentThreadSlot(ProfiledThread* current) { + if (current == nullptr) { + return -1; + } + 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); + } + + // Startup can register this TID centrally, but it cannot update another + // pthread's TLS. registerThread(tid) reuses that existing slot. + slot_id = registerThread(tid); + if (slot_id >= 0) { + current->setFilterSlotId(slot_id); + } + return slot_id; +} + void ThreadFilter::initFreeList() { // Initialize the free list storage for (int i = 0; i < kFreeListSize; ++i) { @@ -400,6 +452,7 @@ void ThreadFilter::unregisterThreadLocked(SlotID slot_id, int expected_tid) { 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); + slot->enableUnownedBlockedFallback(); slot->clearActiveBlockRun(OSThreadState::UNKNOWN); pushToFreeList(slot_id); } @@ -425,6 +478,7 @@ void ThreadFilter::resetRegistrationsLocked() { 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); + slot.enableUnownedBlockedFallback(); slot.clearActiveBlockRun(OSThreadState::UNKNOWN); } } @@ -543,8 +597,10 @@ void ThreadFilter::clearActive() { continue; } - for (auto& slot : chunk->slots) { + for (int slot_idx = 0; slot_idx < kChunkSize; ++slot_idx) { + Slot& slot = chunk->slots[slot_idx]; slot.exitContextWindow(); + slot.enableUnownedBlockedFallback(); slot.clearActiveBlockRun(OSThreadState::UNKNOWN); } } @@ -556,21 +612,29 @@ void ThreadFilter::resetSlotRunState(SlotID slot_id) { int slot_idx = slot_id & kChunkMask; ChunkStorage* chunk = _chunks[chunk_idx].load(std::memory_order_acquire); if (chunk != nullptr) { - // Clear stale suppression state so a new thread in this slot cannot inherit - // its predecessor's active block or once-per-run sampled marker. + // Clear stale suppression state so a new thread in this slot cannot + // inherit its predecessor's active block. + chunk->slots[slot_idx].enableUnownedBlockedFallback(); chunk->slots[slot_idx].clearActiveBlockRun(OSThreadState::UNKNOWN); } } u64 ThreadFilter::enterBlockedRun(SlotID slot_id, OSThreadState state, BlockRunOwner owner) { + if (state == OSThreadState::UNKNOWN) return 0; Slot* s = slotForId(slot_id); if (s != nullptr) { - u32 generation = 0; - if (!s->trySetActiveBlockRun(state, owner, &generation, - unfilteredWallTrackingActive())) { + u64 generation = 0; + if (!s->tryPrepareActiveBlockRun( + owner, &generation, unfilteredWallTrackingActive())) { return 0; } + s->publishActiveBlockRun(state); +#ifdef UNIT_TEST + BlockRunPublishObserver observer = + _block_run_publish_observer.load(std::memory_order_acquire); + if (observer != nullptr) observer(this, slot_id); +#endif return encodeBlockRunToken(slot_id, generation); } return 0; @@ -583,68 +647,99 @@ void ThreadFilter::exitBlockedRun(SlotID slot_id) { } } -bool ThreadFilter::exitBlockedRun(SlotID slot_id, u32 generation) { +bool ThreadFilter::exitBlockedRun(SlotID slot_id, u64 generation) { Slot* s = slotForId(slot_id); - if (s == nullptr || generation == 0 || s->blockGeneration() != generation) { + if (s == nullptr || generation == 0 || + s->activeBlockState() == OSThreadState::UNKNOWN || + s->activeBlockOwner() == BlockRunOwner::NONE || + s->blockGeneration() != generation) { return false; } s->clearActiveBlockRun(OSThreadState::RUNNABLE); return true; } -bool ThreadFilter::shouldSuppressOwnedBlock(const ThreadEntry& entry) const { - Slot* slot = entry.slot; - if (slot == nullptr || slot->nativeTid() != entry.tid || - slot->lifecycleGeneration() != entry.lifecycle_generation) { +bool ThreadFilter::snapshotAndExitBlockedRun(SlotID slot_id, u64 generation, + BlockRunSnapshot* snapshot) { + Slot* s = slotForId(slot_id); + if (s == nullptr || generation == 0 || + s->activeBlockState() == OSThreadState::UNKNOWN || + s->activeBlockOwner() == BlockRunOwner::NONE || + s->blockGeneration() != generation) { return false; } + if (snapshot != nullptr) *snapshot = s->snapshotBlockRun(); + s->clearActiveBlockRun(OSThreadState::RUNNABLE); + return true; +} - const bool unfiltered_tracking = unfilteredWallTrackingActive(); - RecordingEpoch epoch = 0; - if (unfiltered_tracking) { - epoch = recordingEpoch(); - if (epoch == 0 || entry.recording_epoch != epoch || - slot->recordingEpoch() != epoch) { - return false; - } - } +bool ThreadFilter::activeOwnedBlockGeneration(const ThreadEntry& entry, + u64& generation) const { + return ownedBlockGeneration(entry, generation, false); +} -#ifdef UNIT_TEST - if (_suppression_snapshot_hook != nullptr) { - _suppression_snapshot_hook(_suppression_snapshot_hook_arg); +bool ThreadFilter::isOwnedBlockSuppressionCandidate( + const ThreadEntry& entry) const { + u64 generation = 0; + return ownedBlockGeneration(entry, generation, true); +} + +bool ThreadFilter::ownedBlockGeneration(const ThreadEntry& entry, + u64& generation, + bool require_sampled) const { + Slot* slot = entry.slot; + if (!unfilteredWallTrackingActive() || slot == nullptr || + slot->nativeTid() != entry.tid || + slot->lifecycleGeneration() != entry.lifecycle_generation) { + return false; } -#endif - u32 block_generation = slot->blockGeneration(); - BlockRunOwner owner = slot->activeBlockOwner(); + // 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(); - bool context_eligible = - !unfiltered_tracking || slot->activeBlockRemainedOutsideContextWindow(); - bool sampled = slot->sampledThisRun(); - OSThreadState last_sampled_state = - sampled ? slot->lastSampledState() : OSThreadState::UNKNOWN; bool suppressible_state = state == OSThreadState::SLEEPING || state == OSThreadState::CONDVAR_WAIT || state == OSThreadState::OBJECT_WAIT || state == OSThreadState::MONITOR_WAIT; - if (owner == BlockRunOwner::NONE || !context_eligible || - !suppressible_state || !sampled || state != last_sampled_state) { + if (!suppressible_state) return false; + + RecordingEpoch epoch = recordingEpoch(); + if (epoch == 0 || entry.recording_epoch != epoch || + slot->recordingEpoch() != epoch || + !slot->activeBlockRemainedOutsideContextWindow()) { + return false; + } + + u64 block_generation = slot->blockGeneration(); + BlockRunOwner owner = slot->activeBlockOwner(); + if (owner == BlockRunOwner::NONE || + (require_sampled && + slot->sampledBlockGeneration() != block_generation)) { return false; } +#ifdef UNIT_TEST + if (_suppression_snapshot_hook != nullptr) { + _suppression_snapshot_hook(_suppression_snapshot_hook_arg); + } +#endif + // The payload is spread across independent atomics. Accept it only if the // slot still represents the lifecycle and block run captured by the timer. if (slot->activeBlockOwner() != owner || slot->blockGeneration() != block_generation || - slot->nativeTid() != entry.tid || - slot->lifecycleGeneration() != entry.lifecycle_generation) { + slot->activeBlockState() != state || slot->nativeTid() != entry.tid || + slot->lifecycleGeneration() != entry.lifecycle_generation || + (require_sampled && + slot->sampledBlockGeneration() != block_generation)) { return false; } - if (unfiltered_tracking && - (recordingEpoch() != epoch || slot->recordingEpoch() != epoch || - !slot->activeBlockRemainedOutsideContextWindow())) { + if (recordingEpoch() != epoch || slot->recordingEpoch() != epoch || + !slot->activeBlockRemainedOutsideContextWindow()) { return false; } + generation = block_generation; return true; } diff --git a/ddprof-lib/src/main/cpp/threadFilter.h b/ddprof-lib/src/main/cpp/threadFilter.h index 23ec4189bf..ed3f364326 100644 --- a/ddprof-lib/src/main/cpp/threadFilter.h +++ b/ddprof-lib/src/main/cpp/threadFilter.h @@ -26,6 +26,7 @@ #include "arch.h" #include "threadState.h" +class ProfiledThread; struct ThreadEntry; // defined after ThreadFilter; carries a pointer to a ThreadFilter::Slot enum class BlockRunOwner : int { @@ -35,6 +36,14 @@ enum class BlockRunOwner : int { NATIVE = 3, }; +struct BlockRunSnapshot { + OSThreadState active_state{OSThreadState::UNKNOWN}; + BlockRunOwner owner{BlockRunOwner::NONE}; + u64 generation{0}; + bool active{false}; + bool context_eligible{false}; +}; + class ThreadFilter { public: using SlotID = int; @@ -46,6 +55,11 @@ class ThreadFilter { static constexpr int kChunkMask = kChunkSize - 1; static constexpr int kMaxThreads = 2048; static constexpr int kMaxChunks = (kMaxThreads + kChunkSize - 1) / kChunkSize; // = 8 chunks + static constexpr int kBlockRunSlotBits = 11; + static constexpr u64 kBlockRunSlotMask = (1ULL << kBlockRunSlotBits) - 1; + static constexpr u64 kMaxBlockRunGeneration = UINT64_MAX >> kBlockRunSlotBits; + static_assert(kMaxThreads == (1 << kBlockRunSlotBits), + "block-run token slot bits must cover every ThreadFilter slot"); // High-performance free list using Treiber stack, 64 shards static constexpr int kFreeListSize = kMaxThreads; static constexpr int kShardCount = 64; // power-of-two for fast modulo @@ -70,23 +84,21 @@ class ThreadFilter { // release-published. std::atomic recording_epoch{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}; // Native identity and context-window membership are independent so an // unfiltered wall recording can retain lifecycle metadata without // changing ordinary thread selection. std::atomic tid{-1}; 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}; // 4 bytes + 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[2 * DEFAULT_CACHE_LINE_SIZE - sizeof(std::atomic) - sizeof(std::atomic) @@ -95,13 +107,13 @@ class ThreadFilter { - 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) - - sizeof(std::atomic)]; + - sizeof(std::atomic) + - sizeof(std::atomic) + - sizeof(std::atomic)]; inline int nativeTid() const { return tid.load(std::memory_order_acquire); @@ -141,21 +153,6 @@ class ThreadFilter { return false; } - 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); } @@ -165,9 +162,34 @@ class ThreadFilter { 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); } + 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); @@ -205,9 +227,9 @@ class ThreadFilter { } return true; } - inline bool trySetActiveBlockRun(OSThreadState state, BlockRunOwner owner, - u32* generation_out, - bool outside_context_required) { + inline bool tryPrepareActiveBlockRun(BlockRunOwner owner, + u64* generation_out, + bool outside_context_required) { u64 context_state = context_window_state.load(std::memory_order_acquire); if (outside_context_required && (context_state & 1) != 0) { return false; @@ -224,18 +246,27 @@ class ThreadFilter { 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); + 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 clearActiveBlockRun(OSThreadState state) { + inline void publishActiveBlockRun(OSThreadState state) { + active_block_state.store(state, std::memory_order_release); + } + inline void clearActiveBlockRun(OSThreadState) { active_block_state.store(OSThreadState::UNKNOWN, std::memory_order_release); - resetSampledRun(state); + resetSampledBlockGeneration(); + resetUnownedBlockedSampling(); active_block_owner.store(static_cast(BlockRunOwner::NONE), std::memory_order_release); } inline bool activeBlockRemainedOutsideContextWindow() const { @@ -244,12 +275,20 @@ class ThreadFilter { active_block_context_epoch.load(std::memory_order_acquire) == (context_state >> 1); } + inline BlockRunSnapshot snapshotBlockRun() const { + BlockRunSnapshot snapshot; + snapshot.active_state = activeBlockState(); + snapshot.owner = activeBlockOwner(); + snapshot.generation = blockGeneration(); + snapshot.active = snapshot.owner != BlockRunOwner::NONE && + snapshot.active_state != OSThreadState::UNKNOWN; + snapshot.context_eligible = activeBlockRemainedOutsideContextWindow(); + return snapshot; + } }; static_assert(sizeof(Slot) == 2 * DEFAULT_CACHE_LINE_SIZE, "Slot must be exactly two cache lines"); static_assert(std::atomic::is_always_lock_free, "Slot OSThreadState fields must be lock-free for signal-handler safety"); - static_assert(std::atomic::is_always_lock_free, - "Slot::sampled_this_run must be lock-free for signal-handler safety"); static_assert(std::atomic::is_always_lock_free, "Slot::recording_epoch must be lock-free for signal-handler safety"); @@ -278,10 +317,12 @@ class ThreadFilter { // lifecycles must use the generation-checked overload so they cannot clear // another owner. void exitBlockedRun(SlotID slot_id); - bool exitBlockedRun(SlotID slot_id, u32 generation); - // Reads the complete timer-side suppression payload and rejects it if slot - // identity or block lifecycle changes before final validation. - bool shouldSuppressOwnedBlock(const ThreadEntry& entry) const; + bool exitBlockedRun(SlotID slot_id, u64 generation); + bool snapshotAndExitBlockedRun(SlotID slot_id, u64 generation, + BlockRunSnapshot* snapshot); + bool activeOwnedBlockGeneration(const ThreadEntry& entry, + u64& generation) const; + bool isOwnedBlockSuppressionCandidate(const ThreadEntry& entry) const; #ifdef UNIT_TEST using SuppressionSnapshotHook = void (*)(void*); @@ -292,15 +333,27 @@ class ThreadFilter { } #endif - static inline u64 encodeBlockRunToken(SlotID slot_id, u32 generation) { - return (static_cast(generation) << 32) | static_cast(slot_id + 1); + static inline u64 encodeBlockRunToken(SlotID slot_id, u64 generation) { + return (generation << kBlockRunSlotBits) | static_cast(slot_id); } static inline 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, SlotID& slot_id, + u64& generation) { + if (token == 0) return false; + slot_id = tokenSlotId(token); + generation = tokenGeneration(token); + return generation != 0; + } + +#ifdef UNIT_TEST + using BlockRunPublishObserver = void (*)(ThreadFilter*, SlotID); + static void setBlockRunPublishObserverForTest(BlockRunPublishObserver observer); +#endif // Returns nullptr if slot_id is invalid or its chunk has not been allocated. inline Slot* slotForId(SlotID slot_id) const { @@ -318,9 +371,16 @@ class ThreadFilter { Slot* lookupByTid(int tid) const; Slot* lookupByTid(int tid, RecordingEpoch epoch) 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; + SlotID ensureCurrentThreadSlot(ProfiledThread* current); void deactivateRecording(); + SlotID slotIdByTid(int tid) const { return lookupSlotIdByTid(tid); } private: + bool ownedBlockGeneration(const ThreadEntry& entry, u64& generation, + bool require_sampled) const; // Lock-free free list using a stack-like structure struct FreeListNode { @@ -354,6 +414,7 @@ class ThreadFilter { std::mutex _registry_lock; #ifdef UNIT_TEST + static std::atomic _block_run_publish_observer; SuppressionSnapshotHook _suppression_snapshot_hook = nullptr; void* _suppression_snapshot_hook_arg = nullptr; #endif diff --git a/ddprof-lib/src/main/cpp/threadLocalData.h b/ddprof-lib/src/main/cpp/threadLocalData.h index 3f143efa62..f6010761b4 100644 --- a/ddprof-lib/src/main/cpp/threadLocalData.h +++ b/ddprof-lib/src/main/cpp/threadLocalData.h @@ -78,6 +78,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; // Slot ID for thread filtering uint8_t _init_window; // Countdown for JVM thread init race window (PROF-13072) uint8_t _signal_depth; // Nested signal-handler depth (see SignalHandlerScope) @@ -103,7 +106,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) { @@ -354,6 +359,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/wallClock.cpp b/ddprof-lib/src/main/cpp/wallClock.cpp index 19911c6b11..d722ee1b0b 100644 --- a/ddprof-lib/src/main/cpp/wallClock.cpp +++ b/ddprof-lib/src/main/cpp/wallClock.cpp @@ -59,8 +59,8 @@ static inline bool hasKnownActiveTraceContext(ProfiledThread* thread) { struct WallPrecheckResult { bool suppress = false; - ThreadFilter::Slot* slot_to_arm = nullptr; - OSThreadState state_to_arm = OSThreadState::UNKNOWN; + ThreadFilter::Slot* owned_block_slot = nullptr; + u64 owned_block_generation = 0; OSThreadState observed_state = OSThreadState::UNKNOWN; bool observed_state_valid = false; ThreadFilter::Slot* unowned_weight_slot = nullptr; @@ -71,18 +71,17 @@ 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(); } -static inline bool suppressAlreadySampledBlock(const ThreadEntry& entry) { - ThreadFilter* thread_filter = Profiler::instance()->threadFilter(); - if (!thread_filter->shouldSuppressOwnedBlock(entry)) { - return false; +static inline bool suppressOwnedBlock(const ThreadEntry& entry) { + if (Profiler::instance()->threadFilter()->isOwnedBlockSuppressionCandidate(entry)) { + incrementSuppressedOwnedBlock(); + return true; } - incrementSuppressedSampledRun(); - return true; + return false; } static inline WallPrecheckResult prepareWallPrecheck(ProfiledThread* current, @@ -104,39 +103,29 @@ 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 = slot->activeBlockState(); - BlockRunOwner active_block_owner = slot->activeBlockOwner(); - bool has_owned_block = - active_block_owner != BlockRunOwner::NONE && - isPrecheckSuppressionState(active_block_state) && - (!registry->unfilteredWallTrackingActive() || - slot->activeBlockRemainedOutsideContextWindow()); - if (has_owned_block) { - if (slot->sampledThisRun() && - active_block_state == slot->lastSampledState()) { - incrementSuppressedSampledRun(); - 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 = slot; - result.state_to_arm = active_block_state; + ThreadEntry entry{current->tid(), slot, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + if (registry->isOwnedBlockSuppressionCandidate(entry)) { + incrementSuppressedOwnedBlock(); + result.suppress = true; 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()) { + u64 block_generation = 0; + if (registry->activeOwnedBlockGeneration(entry, block_generation)) { + // 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 = slot; + result.owned_block_generation = block_generation; + return result; + } + if (!slot->unownedBlockedFallbackEnabled()) { return result; } @@ -160,6 +149,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); @@ -170,9 +163,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, @@ -262,12 +252,10 @@ void WallClockASGCT::signalHandler(int signo, siginfo_t *siginfo, void *ucontext current->tickInitWindow(); 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; @@ -391,7 +379,7 @@ void WallClockASGCT::timerLoop() { } if (_precheck && !lazy_backfill) { entries.erase(std::remove_if(entries.begin(), entries.end(), - suppressAlreadySampledBlock), + suppressOwnedBlock), entries.end()); } }; @@ -401,19 +389,11 @@ void WallClockASGCT::timerLoop() { int& registry_lookups, bool lookup_registry_slot) { if (lookup_registry_slot && entry.slot == nullptr) { registry_lookups++; - ThreadFilter::Slot* slot = - thread_filter->lookupByTid(entry.tid, recording_epoch); - if (slot != nullptr) { - entry.slot = slot; - entry.lifecycle_generation = slot->lifecycleGeneration(); - entry.recording_epoch = slot->recordingEpoch(); - } + thread_filter->lookupThreadEntry(entry, recording_epoch); } - // Timer-thread fast path (wallprecheck=true): skip the kernel IPI entirely - // only when an explicit lifecycle hook still owns an already-sampled blocked - // run. Raw OS thread state is intentionally not used here because the timer - // thread cannot prove run boundaries for the target thread. - if (_precheck && suppressAlreadySampledBlock(entry)) { + // Timer-thread fast path (wallprecheck=true): skip the kernel IPI only + // after an explicitly owned run has recorded its first MethodSample. + if (_precheck && suppressOwnedBlock(entry)) { return WallClockCandidateOutcome::PRECHECK_REJECTED; } if (!OS::sendSignalWithCookie(entry.tid, SIGVTALRM, SignalCookie::wallclock())) { @@ -515,8 +495,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. + // JVMTI-delegated samples carry no call_trace_id, so unowned tail flushing + // remains limited to the ASGCT wall engine. bool recorded = Profiler::instance()->recordSampleDelegated( nullptr, last_sample, tid, BCI_WALL, &event); finishWallPrecheck(precheck, recorded); @@ -556,7 +536,7 @@ void WallClockJvmti::timerLoop() { } if (_precheck && !lazy_backfill) { entries.erase(std::remove_if(entries.begin(), entries.end(), - suppressAlreadySampledBlock), + suppressOwnedBlock), entries.end()); } }; @@ -566,15 +546,9 @@ void WallClockJvmti::timerLoop() { int ®istry_lookups, bool lookup_registry_slot) { if (lookup_registry_slot && entry.slot == nullptr) { registry_lookups++; - ThreadFilter::Slot* slot = - thread_filter->lookupByTid(entry.tid, recording_epoch); - if (slot != nullptr) { - entry.slot = slot; - entry.lifecycle_generation = slot->lifecycleGeneration(); - entry.recording_epoch = slot->recordingEpoch(); - } + thread_filter->lookupThreadEntry(entry, recording_epoch); } - if (_precheck && suppressAlreadySampledBlock(entry)) { + if (_precheck && suppressOwnedBlock(entry)) { return WallClockCandidateOutcome::PRECHECK_REJECTED; } if (!OS::sendSignalWithCookie(entry.tid, SIGVTALRM, SignalCookie::wallclock())) { diff --git a/ddprof-lib/src/main/cpp/wallClock.h b/ddprof-lib/src/main/cpp/wallClock.h index 8bd9ef8c66..e0f819eefe 100644 --- a/ddprof-lib/src/main/cpp/wallClock.h +++ b/ddprof-lib/src/main/cpp/wallClock.h @@ -138,7 +138,7 @@ class BaseWallClock : public Engine { epoch.updateNumSamplableThreads(threads.size()); 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/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 eab2de7580..de7f876e49 100644 --- a/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfiler.java +++ b/ddprof-lib/src/main/java/com/datadoghq/profiler/JavaProfiler.java @@ -530,8 +530,8 @@ 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. */ void parkEnter() { parkEnter0(); @@ -539,7 +539,7 @@ void parkEnter() { /** * 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); @@ -547,7 +547,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 @@ -564,6 +564,34 @@ 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); + } + /** * Get the ticks for the current thread. * @return ticks @@ -627,6 +655,11 @@ private static ThreadContext initializeThreadContext() { 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 6557567ebc..42f5e4658c 100644 --- a/ddprof-lib/src/test/cpp/jvmSupport_ut.cpp +++ b/ddprof-lib/src/test/cpp/jvmSupport_ut.cpp @@ -37,6 +37,127 @@ class JvmSupportGlobalSetup { }; static JvmSupportGlobalSetup jvm_support_global_setup; +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; + + 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 { + 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); + } +}; + +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); +} + // --------------------------------------------------------------------------- // VMTestAccessor — friend of VM, lets tests swap VM::_jvmti for a mock so // JVMThread::currentThreadSlow() can be exercised without a live JVM. diff --git a/ddprof-lib/src/test/cpp/park_state_ut.cpp b/ddprof-lib/src/test/cpp/park_state_ut.cpp index 69f3792424..5a236994e0 100644 --- a/ddprof-lib/src/test/cpp/park_state_ut.cpp +++ b/ddprof-lib/src/test/cpp/park_state_ut.cpp @@ -39,7 +39,7 @@ TestProfiledThread testThread(int tid) { } // namespace -// Tests cover FLAG_PARKED lifecycle and the once-per-run slot filter state transitions. +// Tests cover FLAG_PARKED lifecycle and owned-block slot 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. @@ -137,48 +137,18 @@ TEST(ProfiledThreadParkStateTest, ParkExitReturnsZeroTokenWhenBlockRunWasNotArme EXPECT_EQ(0ULL, park_block_token); } -TEST(WallClockOncePerRunFilterTest, SlotStateTransitions) { +TEST(WallClockOwnedBlockFilterTest, SlotStateTransitions) { ThreadFilter::Slot 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) { @@ -332,33 +302,24 @@ 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()); - filter.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; filter.init("1"); ThreadFilter::SlotID slot_id = filter.registerThread(); filter.enterBlockedRun(slot_id, OSThreadState::CONDVAR_WAIT); ThreadFilter::Slot *slot = filter.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..9745609ad6 --- /dev/null +++ b/ddprof-lib/src/test/cpp/taskBlockRecorder_ut.cpp @@ -0,0 +1,237 @@ +/* + * 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, RotationRejectsEndWithoutStrandingLifecycle) { + constexpr int tid = 12345; + ThreadFilter filter; + 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 = filter.enterBlockedRun( + 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, nullptr, 1, token, + ThreadFilter::tokenSlotId(token), + ThreadFilter::tokenGeneration(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) { + ThreadFilter::Slot* slot = filter.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 = filter.enterBlockedRun( + 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(filter.exitBlockedRun( + slot_id, ThreadFilter::tokenGeneration(next_token))); + } + + profiler->endTaskBlockRotationForTest(); + EXPECT_FALSE(result.get()); + EXPECT_EQ(1, Counters::getCounter(TASK_BLOCK_DROPPED_ROTATION)); +} + +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 004187b483..0ed6c86804 100644 --- a/ddprof-lib/src/test/cpp/threadFilter_ut.cpp +++ b/ddprof-lib/src/test/cpp/threadFilter_ut.cpp @@ -495,7 +495,6 @@ TEST_F(ThreadFilterTest, ClearActiveDropsPreviousRecordingMembership) { filter->enterBlockedRun(stale_slot, OSThreadState::SLEEPING); ThreadFilter::Slot *stale = filter->slotForId(stale_slot); ASSERT_NE(nullptr, stale); - stale->markSampledThisRun(OSThreadState::SLEEPING); filter->clearActive(); @@ -504,8 +503,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); @@ -553,15 +550,181 @@ TEST_F(ThreadFilterTest, NewGenerationRejectsStaleToken) { EXPECT_TRUE(filter->exitBlockedRun(slot_id, ThreadFilter::tokenGeneration(current_token))); } -TEST_F(ThreadFilterTest, TokenRoundTripPreservesHighGenerationBit) { +TEST_F(ThreadFilterTest, TokenRoundTripPreservesNegativeJavaLongBitPattern) { ThreadFilter::SlotID slot_id = 7; - u32 generation = 0x80000001u; + u64 generation = 1ULL << 52; u64 token = ThreadFilter::encodeBlockRunToken(slot_id, generation); int64_t java_token = static_cast(token); EXPECT_LT(java_token, 0); - EXPECT_EQ(slot_id, ThreadFilter::tokenSlotId(static_cast(java_token))); - EXPECT_EQ(generation, ThreadFilter::tokenGeneration(static_cast(java_token))); + ThreadFilter::SlotID decoded_slot = -1; + u64 decoded_generation = 0; + EXPECT_TRUE(ThreadFilter::decodeBlockRunToken( + static_cast(java_token), decoded_slot, decoded_generation)); + EXPECT_EQ(slot_id, decoded_slot); + EXPECT_EQ(generation, decoded_generation); +} + +TEST_F(ThreadFilterTest, TokenRoundTripCoversSlotAndGenerationBoundaries) { + ThreadFilter::SlotID decoded_slot = -1; + u64 decoded_generation = 0; + + u64 first = ThreadFilter::encodeBlockRunToken(0, 1); + ASSERT_TRUE(ThreadFilter::decodeBlockRunToken( + first, decoded_slot, decoded_generation)); + EXPECT_EQ(0, decoded_slot); + EXPECT_EQ(1ULL, decoded_generation); + + u64 last = ThreadFilter::encodeBlockRunToken( + ThreadFilter::kMaxThreads - 1, ThreadFilter::kMaxBlockRunGeneration); + EXPECT_EQ(UINT64_MAX, last); + ASSERT_TRUE(ThreadFilter::decodeBlockRunToken( + last, decoded_slot, decoded_generation)); + EXPECT_EQ(ThreadFilter::kMaxThreads - 1, decoded_slot); + EXPECT_EQ(ThreadFilter::kMaxBlockRunGeneration, decoded_generation); + + EXPECT_FALSE(ThreadFilter::decodeBlockRunToken( + 0, decoded_slot, decoded_generation)); + EXPECT_FALSE(ThreadFilter::decodeBlockRunToken( + static_cast(ThreadFilter::kMaxThreads - 1), + decoded_slot, decoded_generation)); +} + +TEST_F(ThreadFilterTest, SaturatedGenerationRefusesEntryWithoutClaimingSlot) { + int slot_id = filter->registerThread(); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + slot->block_generation.store(ThreadFilter::kMaxBlockRunGeneration - 1, + std::memory_order_release); + + u64 token = filter->enterBlockedRun(slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + EXPECT_EQ(ThreadFilter::kMaxBlockRunGeneration, + ThreadFilter::tokenGeneration(token)); + ASSERT_TRUE(filter->exitBlockedRun( + slot_id, ThreadFilter::tokenGeneration(token))); + + EXPECT_EQ(0ULL, filter->enterBlockedRun(slot_id, OSThreadState::SLEEPING)); + EXPECT_EQ(0ULL, filter->enterBlockedRun(slot_id, OSThreadState::SLEEPING)); + EXPECT_EQ(BlockRunOwner::NONE, slot->activeBlockOwner()); + EXPECT_EQ(OSThreadState::UNKNOWN, slot->activeBlockState()); + EXPECT_EQ(ThreadFilter::kMaxBlockRunGeneration, slot->blockGeneration()); +} + +TEST_F(ThreadFilterTest, SnapshotCapturesOwnedLifecycle) { + int slot_id = filter->registerThread(); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + u64 token = filter->enterBlockedRun(slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + + BlockRunSnapshot snapshot = slot->snapshotBlockRun(); + EXPECT_TRUE(snapshot.active); + EXPECT_EQ(OSThreadState::SLEEPING, snapshot.active_state); + EXPECT_EQ(BlockRunOwner::JAVA, snapshot.owner); + EXPECT_EQ(ThreadFilter::tokenGeneration(token), snapshot.generation); + + ASSERT_TRUE(filter->snapshotAndExitBlockedRun( + slot_id, ThreadFilter::tokenGeneration(token), &snapshot)); + EXPECT_FALSE(slot->snapshotBlockRun().active); +} + +TEST_F(ThreadFilterTest, OwnedBlockSuppressesOnlyAfterSuccessfulWallSample) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + u64 token = filter->enterBlockedRun(slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, token); + + ThreadEntry entry{1234, slot, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + u64 generation = 0; + EXPECT_TRUE(filter->activeOwnedBlockGeneration(entry, generation)); + EXPECT_EQ(ThreadFilter::tokenGeneration(token), generation); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate(entry)); + + slot->markBlockGenerationSampled(generation); + EXPECT_TRUE(filter->isOwnedBlockSuppressionCandidate(entry)); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate( + {1235, slot, slot->lifecycleGeneration(), slot->recordingEpoch()})); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate( + {1234, slot, slot->lifecycleGeneration() + 1, + slot->recordingEpoch()})); + + ASSERT_TRUE(filter->exitBlockedRun( + slot_id, ThreadFilter::tokenGeneration(token))); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate(entry)); +} + +TEST_F(ThreadFilterTest, StaleSampleCompletionCannotSuppressNewBlockGeneration) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + + u64 first_token = filter->enterBlockedRun(slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0ULL, first_token); + u64 first_generation = ThreadFilter::tokenGeneration(first_token); + ASSERT_TRUE(filter->exitBlockedRun(slot_id, first_generation)); + + u64 second_token = + filter->enterBlockedRun(slot_id, OSThreadState::CONDVAR_WAIT); + ASSERT_NE(0ULL, second_token); + u64 second_generation = ThreadFilter::tokenGeneration(second_token); + ASSERT_GT(second_generation, first_generation); + + ThreadEntry entry{1234, slot, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + slot->markBlockGenerationSampled(first_generation); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate(entry)); + + slot->markBlockGenerationSampled(second_generation); + EXPECT_TRUE(filter->isOwnedBlockSuppressionCandidate(entry)); + + // A delayed completion from the first run must not overwrite the newer mark. + slot->markBlockGenerationSampled(first_generation); + EXPECT_EQ(second_generation, slot->sampledBlockGeneration()); + EXPECT_TRUE(filter->isOwnedBlockSuppressionCandidate(entry)); +} + +TEST_F(ThreadFilterTest, 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); + ASSERT_NE(nullptr, slot); + ASSERT_NE(0ULL, filter->enterBlockedRun( + slot_id, OSThreadState::CONDVAR_WAIT)); + + ThreadEntry entry{1234, slot, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + slot->markBlockGenerationSampled(slot->blockGeneration()); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate(entry)); +} + +TEST_F(ThreadFilterTest, ContextEpochDisablesOwnedBlockSuppression) { + filter->init(nullptr, true); + int slot_id = filter->registerThread(1234); + ASSERT_GE(slot_id, 0); + ThreadFilter::Slot* slot = filter->slotForId(slot_id); + ASSERT_NE(nullptr, slot); + ASSERT_NE(0ULL, filter->enterBlockedRun( + slot_id, OSThreadState::CONDVAR_WAIT)); + ThreadEntry entry{1234, slot, slot->lifecycleGeneration(), + slot->recordingEpoch()}; + slot->markBlockGenerationSampled(slot->blockGeneration()); + ASSERT_TRUE(filter->isOwnedBlockSuppressionCandidate(entry)); + + filter->add(1234, slot_id); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate(entry)); + filter->remove(slot_id); + EXPECT_FALSE(filter->isOwnedBlockSuppressionCandidate(entry)); } class ThreadRegistryTest : public ::testing::Test { @@ -603,6 +766,25 @@ TEST_F(ThreadRegistryTest, UnfilteredTrackingSeparatesRegistrationFromContextWin EXPECT_TRUE(context.empty()); } +TEST_F(ThreadRegistryTest, LookupThreadEntryDoesNotRegisterUnknownTid) { + constexpr int tid = 3210; + ThreadEntry entry{tid, nullptr, 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->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); @@ -612,14 +794,13 @@ TEST_F(ThreadRegistryTest, RegisteringKnownTidReturnsExistingSlotWithoutMutation u64 token = registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING); ASSERT_NE(0ULL, token); - 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, slot->activeBlockState()); - EXPECT_TRUE(slot->sampledThisRun()); + EXPECT_EQ(BlockRunOwner::JAVA, slot->activeBlockOwner()); EXPECT_TRUE(registry.exitBlockedRun( slot_id, ThreadFilter::tokenGeneration(token))); } @@ -708,7 +889,6 @@ TEST_F(ThreadRegistryTest, ContextTransitionInvalidatesOwnedRunSuppression) { u64 token = registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING); ASSERT_NE(0u, token); - slot->markSampledThisRun(OSThreadState::SLEEPING); EXPECT_TRUE(slot->activeBlockRemainedOutsideContextWindow()); registry.add(3333, slot_id); @@ -717,7 +897,7 @@ TEST_F(ThreadRegistryTest, ContextTransitionInvalidatesOwnedRunSuppression) { ThreadEntry entry{3333, slot, slot->lifecycleGeneration(), slot->recordingEpoch()}; - EXPECT_FALSE(registry.shouldSuppressOwnedBlock(entry)); + EXPECT_FALSE(registry.isOwnedBlockSuppressionCandidate(entry)); } TEST_F(ThreadRegistryTest, UnfilteredSuppressionValidatesIdentityAndLifecycle) { @@ -728,24 +908,24 @@ TEST_F(ThreadRegistryTest, UnfilteredSuppressionValidatesIdentityAndLifecycle) { u64 token = registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING); ASSERT_NE(0u, token); - slot->markSampledThisRun(OSThreadState::SLEEPING); + slot->markBlockGenerationSampled(ThreadFilter::tokenGeneration(token)); ThreadEntry entry{4444, slot, slot->lifecycleGeneration(), slot->recordingEpoch()}; - EXPECT_TRUE(registry.shouldSuppressOwnedBlock(entry)); + EXPECT_TRUE(registry.isOwnedBlockSuppressionCandidate(entry)); ThreadEntry wrong_tid{4445, slot, entry.lifecycle_generation, entry.recording_epoch}; - EXPECT_FALSE(registry.shouldSuppressOwnedBlock(wrong_tid)); + EXPECT_FALSE(registry.isOwnedBlockSuppressionCandidate(wrong_tid)); ThreadEntry stale_generation{4444, slot, entry.lifecycle_generation + 1, entry.recording_epoch}; - EXPECT_FALSE(registry.shouldSuppressOwnedBlock(stale_generation)); + EXPECT_FALSE(registry.isOwnedBlockSuppressionCandidate(stale_generation)); EXPECT_TRUE(registry.exitBlockedRun( slot_id, ThreadFilter::tokenGeneration(token))); - EXPECT_FALSE(registry.shouldSuppressOwnedBlock(entry)); + EXPECT_FALSE(registry.isOwnedBlockSuppressionCandidate(entry)); } -TEST_F(ThreadRegistryTest, ContextFilteredSuppressionPreservesHistoricalEligibility) { +TEST_F(ThreadRegistryTest, ContextFilteredSuppressionRemainsDisabled) { registry.init("0"); int slot_id = registry.registerThread(5555); ASSERT_GE(slot_id, 0); @@ -755,10 +935,9 @@ TEST_F(ThreadRegistryTest, ContextFilteredSuppressionPreservesHistoricalEligibil u64 token = registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING); ASSERT_NE(0u, token); - slot->markSampledThisRun(OSThreadState::SLEEPING); ThreadEntry entry{5555, slot, slot->lifecycleGeneration(), slot->recordingEpoch()}; - EXPECT_TRUE(registry.shouldSuppressOwnedBlock(entry)); + EXPECT_FALSE(registry.isOwnedBlockSuppressionCandidate(entry)); } TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { @@ -767,8 +946,9 @@ TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { ASSERT_GE(slot_id, 0); ThreadFilter::Slot* slot = registry.slotForId(slot_id); ASSERT_NE(nullptr, slot); - ASSERT_NE(0u, registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING)); - slot->markSampledThisRun(OSThreadState::SLEEPING); + u64 token = registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING); + ASSERT_NE(0u, token); + slot->markBlockGenerationSampled(ThreadFilter::tokenGeneration(token)); ThreadEntry stale{tid, slot, slot->lifecycleGeneration(), slot->recordingEpoch()}; @@ -788,7 +968,7 @@ TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { std::atomic suppressed{true}; std::thread reader([&] { - suppressed.store(registry.shouldSuppressOwnedBlock(stale), + suppressed.store(registry.isOwnedBlockSuppressionCandidate(stale), std::memory_order_release); }); auto deadline = std::chrono::steady_clock::now() + std::chrono::seconds(5); @@ -807,9 +987,6 @@ TEST_F(ThreadRegistryTest, ConcurrentTidReuseInvalidatesSuppressionSnapshot) { int reused_id = registry.registerThread(tid); ThreadFilter::Slot* reused = registry.slotForId(reused_id); u64 new_token = registry.enterBlockedRun(reused_id, OSThreadState::SLEEPING); - if (reused != nullptr && new_token != 0) { - reused->markSampledThisRun(OSThreadState::SLEEPING); - } pause.resume.store(true, std::memory_order_release); reader.join(); @@ -862,10 +1039,10 @@ TEST_F(ThreadRegistryTest, NewUnfilteredRecordingReclaimsRetainedSlot) { u64 token = registry.enterBlockedRun(slot_id, OSThreadState::SLEEPING); ASSERT_NE(0u, token); - slot->markSampledThisRun(OSThreadState::SLEEPING); + slot->markBlockGenerationSampled(ThreadFilter::tokenGeneration(token)); ThreadEntry stale{tid, slot, slot->lifecycleGeneration(), slot->recordingEpoch()}; - ASSERT_TRUE(registry.shouldSuppressOwnedBlock(stale)); + ASSERT_TRUE(registry.isOwnedBlockSuppressionCandidate(stale)); registry.init("", true); ThreadFilter::RecordingEpoch second_epoch = registry.recordingEpoch(); @@ -875,11 +1052,10 @@ TEST_F(ThreadRegistryTest, NewUnfilteredRecordingReclaimsRetainedSlot) { EXPECT_EQ(nullptr, registry.lookupByTid(tid)); EXPECT_EQ(-1, slot->nativeTid()); EXPECT_GT(slot->lifecycleGeneration(), first_lifecycle_generation); - EXPECT_FALSE(registry.shouldSuppressOwnedBlock(stale)); + EXPECT_FALSE(registry.isOwnedBlockSuppressionCandidate(stale)); EXPECT_EQ(slot_id, registry.registerThread(tid)); EXPECT_EQ(slot, registry.lookupByTid(tid, second_epoch)); - EXPECT_FALSE(slot->sampledThisRun()); EXPECT_EQ(OSThreadState::UNKNOWN, slot->activeBlockState()); EXPECT_EQ(BlockRunOwner::NONE, slot->activeBlockOwner()); } 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-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java index b3052f3a20..4efc30cb1b 100644 --- a/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/JavaProfilerApiSurfaceTest.java @@ -11,19 +11,25 @@ import java.lang.reflect.Modifier; 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 { + public void taskBlockApiIsPublicButInternalHooksRemainPackageScoped() throws Exception { assertNotPublic(JavaProfiler.class.getDeclaredMethod("parkEnter")); 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())); } 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/wallclock/JavaProfilerTaskBlockApiTest.java b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockApiTest.java new file mode 100644 index 0000000000..1dc1ff692d --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockApiTest.java @@ -0,0 +1,246 @@ +/* + * 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 org.openjdk.jmc.common.item.IItemCollection; + +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(); + + IItemCollection 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"); + } + + @Test + public void traceContextRejectsAtEntry() throws Exception { + AtomicLong token = new AtomicLong(-1L); + runWorker(() -> { + profiler.setContext(0x5100L, 0x5101L, 0L, 0x5101L); + try { + token.set(profiler.beginTaskBlock()); + } finally { + profiler.clearContext(); + } + }); + assertEquals(0L, token.get(), + "a traced interval must not arm timer-side suppression"); + } + + @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..5c0ab26af1 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/JavaProfilerTaskBlockLightweightTest.java @@ -0,0 +1,86 @@ +/* + * 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 org.openjdk.jmc.common.item.IItemCollection; +import org.openjdk.jmc.common.item.IItemIterable; + +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(); + IItemCollection events = verifyEvents("datadog.TaskBlock"); + assertEquals(1L, events.stream().flatMap(IItemIterable::stream).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..8777a6c785 --- /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 org.openjdk.jmc.common.item.IItemCollection; + +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(); + + IItemCollection 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 22a2926d18..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,wallscope=all,wallprecheck=true,jvmtistacks=true"; + return "wall=1ms,filter=,wallprecheck=true,jvmtistacks=true"; } @Override protected String getPrecheckDisabledProfilerCommand() { - return "wall=1ms,wallscope=all,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 6be24b5bba..b33c9592fe 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 @@ -27,9 +27,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. */ @@ -48,23 +48,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) {} @@ -73,7 +70,6 @@ public void compareSuppressionRates() throws Exception { // RUNNABLE — not skipped Thread working = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); ready.countDown(); long x = 0; while (!stop.get()) { x++; } @@ -210,10 +206,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; @@ -227,7 +220,6 @@ public void realisticServiceWorkload() throws Exception { Thread.sleep(50); Thread scheduler = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); while (!stop.get()) { try { Thread.sleep(SCHEDULE_INTERVAL_MS); @@ -246,7 +238,6 @@ public void realisticServiceWorkload() throws Exception { scheduler.start(); Thread hotThread = new Thread(() -> { - registerCurrentThreadForWallClockProfiling(); long x = 0; while (!stop.get()) { x++; } }, "realistic-hot"); @@ -269,8 +260,16 @@ public void realisticServiceWorkload() throws Exception { for (IItemIterable batch : events) { IMemberAccessor stackAccessor = JdkAttributes.STACK_TRACE_STRING.getAccessor(batch.getType()); - if (stackAccessor == null) continue; + IMemberAccessor threadNameAccessor = + JdkAttributes.EVENT_THREAD_NAME.getAccessor(batch.getType()); + if (stackAccessor == null || threadNameAccessor == null) continue; for (IItem item : batch) { + String threadName = threadNameAccessor.getMember(item); + if (threadName == null || (!threadName.startsWith("realistic-pool-") + && !"realistic-scheduler".equals(threadName) + && !"realistic-hot".equals(threadName))) { + continue; + } String stack = stackAccessor.getMember(item); if (stack == null) { otherSamples++; @@ -314,8 +313,8 @@ public void realisticServiceWorkload() throws Exception { @Override protected String getProfilerCommand() { - // The workload deliberately has no tracing context, so its samples - // require the explicit all-thread wall-clock scope. - return "wall=1ms,wallscope=all"; + // The workload deliberately has no tracing context, so keep unfiltered + // wall-clock sampling enabled explicitly. + 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 0afa2694ee..452e86dacf 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 @@ -16,7 +16,6 @@ import org.openjdk.jmc.common.item.IItemCollection; import org.openjdk.jmc.common.item.IItemIterable; import org.openjdk.jmc.common.item.IMemberAccessor; -import org.openjdk.jmc.common.item.Aggregators; import org.openjdk.jmc.common.unit.IQuantity; import org.openjdk.jmc.common.unit.UnitLookup; import org.openjdk.jmc.flightrecorder.jdk.JdkAttributes; @@ -30,8 +29,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 { @@ -49,7 +48,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"); @@ -61,17 +59,16 @@ public void testSleepingThreadIsNotSampled() throws InterruptedException { stopProfiler(); - long sampleCount = verifyEvents("datadog.MethodSample", false) - .getAggregate(Aggregators.count()).longValue(); - // 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()"); } } @@ -80,16 +77,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) - .getAggregate(Aggregators.count()).longValue(); - 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 @@ -98,7 +98,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); @@ -120,19 +119,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.setContext(0x5100L, 0x5101L, 0L, 0x5101L); @@ -144,17 +143,16 @@ public void tracedSleepingThreadIsSampled() throws InterruptedException { stopProfiler(); - long sampleCount = verifyEvents("datadog.MethodSample", false) - .getAggregate(Aggregators.count()).longValue(); + 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"); } } @@ -162,16 +160,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"); @@ -181,11 +178,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"); } /** @@ -202,13 +199,30 @@ private void leaveClearedInitializedContext() { @Override protected String getProfilerCommand() { // This suite verifies sampling and suppression for threads outside a - // tracing-context window. Keep that population in scope explicitly; - // the production default remains wallscope=context. - return "wall=1ms,wallscope=all,wallprecheck=true"; + // tracing-context window. Keep that population in scope explicitly. + return "wall=1ms,filter=,wallprecheck=true"; } protected String getPrecheckDisabledProfilerCommand() { - return "wall=1ms,wallscope=all,wallprecheck=false"; + return "wall=1ms,filter=,wallprecheck=false"; + } + + private long samplesForThread(String threadName) { + long count = 0; + IItemCollection events = verifyEvents("datadog.MethodSample", false); + for (IItemIterable batch : events) { + IMemberAccessor threadNameAccessor = + JdkAttributes.EVENT_THREAD_NAME.getAccessor(batch.getType()); + if (threadNameAccessor == null) { + continue; + } + for (IItem item : batch) { + if (threadName.equals(threadNameAccessor.getMember(item))) { + 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..2752966cd0 --- /dev/null +++ b/ddprof-test/src/test/java/com/datadoghq/profiler/wallclock/TaskBlockAssertions.java @@ -0,0 +1,140 @@ +/* + * Copyright 2026, Datadog, Inc. + * SPDX-License-Identifier: Apache-2.0 + */ + +package com.datadoghq.profiler.wallclock; + +import com.datadoghq.profiler.AbstractProfilerTest; +import java.util.HashSet; +import java.util.Set; +import org.openjdk.jmc.common.IMCFrame; +import org.openjdk.jmc.common.IMCStackTrace; +import org.openjdk.jmc.common.item.IAttribute; +import org.openjdk.jmc.common.item.IItem; +import org.openjdk.jmc.common.item.IItemCollection; +import org.openjdk.jmc.common.item.IItemIterable; +import org.openjdk.jmc.common.item.IMemberAccessor; +import org.openjdk.jmc.common.unit.IQuantity; + +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.openjdk.jmc.common.item.Attribute.attr; +import static org.openjdk.jmc.common.unit.UnitLookup.NUMBER; +import static org.openjdk.jmc.common.unit.UnitLookup.PLAIN_TEXT; + +/** Assertions for the synchronous {@code datadog.TaskBlock} event contract. */ +final class TaskBlockAssertions { + private static final IAttribute BLOCKER = + attr("blocker", "blocker", "Blocker Identity Hash", NUMBER); + private static final IAttribute UNBLOCKING_SPAN_ID = + attr("unblockingSpanId", "unblockingSpanId", "Unblocking Span ID", NUMBER); + private static final IAttribute ANCHOR_SAMPLE_ID = + attr("anchorSampleId", "anchorSampleId", "Anchor MethodSample ID", NUMBER); + private static final IAttribute SUPPRESSED_SAMPLE_COUNT = + attr("suppressedSampleCount", "suppressedSampleCount", "Suppressed Sample Count", NUMBER); + private static final IAttribute OBSERVED_BLOCKING_STATE = + attr("observedBlockingState", "observedBlockingState", "Observed Blocking State", PLAIN_TEXT); + private static final IAttribute CORRELATION_ID = + attr("correlationId", "correlationId", "Async Stack Trace Correlation ID", NUMBER); + + private TaskBlockAssertions() {} + + static void assertContains(IItemCollection events, long rootSpanId, long spanId, + long blocker, long unblockingSpanId) { + for (IItemIterable iterable : events) { + IMemberAccessor root = + AbstractProfilerTest.LOCAL_ROOT_SPAN_ID.getAccessor(iterable.getType()); + IMemberAccessor span = + AbstractProfilerTest.SPAN_ID.getAccessor(iterable.getType()); + IMemberAccessor blockerAccessor = + BLOCKER.getAccessor(iterable.getType()); + IMemberAccessor unblocking = + UNBLOCKING_SPAN_ID.getAccessor(iterable.getType()); + if (root == null || span == null || blockerAccessor == null || unblocking == null) continue; + for (IItem item : iterable) { + if (root.getMember(item).longValue() == rootSpanId + && span.getMember(item).longValue() == spanId + && blockerAccessor.getMember(item).longValue() == blocker + && unblocking.getMember(item).longValue() == unblockingSpanId) { + return; + } + } + } + throw new AssertionError("Expected TaskBlock blocker=" + blocker + + ", unblockingSpanId=" + unblockingSpanId); + } + + static void assertContainsObservedState(IItemCollection events, String expected) { + Set states = new HashSet<>(); + for (IItemIterable iterable : events) { + IMemberAccessor accessor = + OBSERVED_BLOCKING_STATE.getAccessor(iterable.getType()); + if (accessor == null) continue; + for (IItem item : iterable) states.add(accessor.getMember(item)); + } + assertTrue(states.contains(expected), () -> "Observed states: " + states); + } + + static void assertContainsStackTrace(IItemCollection events) { + int count = 0; + for (IItemIterable iterable : events) { + IMemberAccessor accessor = + AbstractProfilerTest.STACK_TRACE.getAccessor(iterable.getType()); + assertTrue(accessor != null, "TaskBlock must expose stackTrace"); + for (IItem item : iterable) { + IMCStackTrace stack = accessor.getMember(item); + assertTrue(stack != null && !stack.getFrames().isEmpty()); + count++; + } + } + assertTrue(count > 0, "Expected a TaskBlock with a non-empty stack"); + } + + static void assertContainsNoStackTrace(IItemCollection events) { + int count = 0; + for (IItemIterable iterable : events) { + IMemberAccessor accessor = + AbstractProfilerTest.STACK_TRACE.getAccessor(iterable.getType()); + assertTrue(accessor != null, "TaskBlock must expose stackTrace"); + for (IItem item : iterable) { + assertNull(accessor.getMember(item)); + count++; + } + } + assertTrue(count > 0, "Expected a TaskBlock without a stack"); + } + + static void assertContainsJavaType(IItemCollection events, String expected) { + for (IItemIterable iterable : events) { + IMemberAccessor accessor = + AbstractProfilerTest.STACK_TRACE.getAccessor(iterable.getType()); + if (accessor == null) continue; + for (IItem item : iterable) { + IMCStackTrace stack = accessor.getMember(item); + if (stack == null) continue; + for (IMCFrame frame : stack.getFrames()) { + if (frame.getMethod() != null + && frame.getMethod().getType() != null + && frame.getMethod().getType().getFullName().contains(expected)) { + return; + } + } + } + } + throw new AssertionError("Expected TaskBlock stack type containing " + expected); + } + + static void assertNoCorrelationId(IItemCollection events) { + for (IItemIterable iterable : events) { + assertNull(CORRELATION_ID.getAccessor(iterable.getType())); + } + } + + static void assertNoAnchorFields(IItemCollection events) { + for (IItemIterable iterable : events) { + assertNull(ANCHOR_SAMPLE_ID.getAccessor(iterable.getType())); + assertNull(SUPPRESSED_SAMPLE_COUNT.getAccessor(iterable.getType())); + } + } +} 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 d7db149f29..95526e9e18 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 @@ -5,7 +5,6 @@ package com.datadoghq.profiler.wallclock; -import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertSame; import static org.junit.jupiter.api.Assertions.assertTrue; @@ -31,14 +30,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 */ @@ -98,11 +97,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(); @@ -110,28 +107,25 @@ 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"); - } } /** - * Retains coverage for post-start threads, whose owned-block hook must register a slot lazily. + * Retains coverage for threads whose registry slot is installed by a post-start ThreadStart + * event. * * @throws Exception if the worker cannot complete */ @RetryingTest(3) - public void postStartSleepingThreadLazilyRegistersOwnedBlock() throws Exception { + public void postStartSleepingThreadUsesThreadStartSlot() throws Exception { String threadName = "unfiltered-precheck-post-start"; + long suppressedBefore = suppressedSignals(); assertTrue( runPostStartSleepingWorker(threadName) != 0, - "Expected the owned-block hook to register and arm SLEEPING state"); + "Expected ThreadStart registration to arm SLEEPING state"); stopProfiler(); assertSuppressedSamples(threadName); + assertOwnedBlockSuppressionObserved(suppressedBefore); } @Override @@ -252,19 +246,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 a2caa1b8a5..bbaf518b5a 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; @@ -23,15 +24,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), @@ -39,6 +37,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( @@ -109,20 +109,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