Skip to content

Commit 9972bff

Browse files
jbachorikclaude
andcommitted
Fix concurrency, overflow, and validation issues in reference-chain tracking
Addresses review findings from PR #644 (reference chains for surviving live-heap samples): FrontierTable's shared-lock mutation race, a single-byte JFR event size prefix that silently truncates chains longer than 255 bytes, blocking sample-lock retries in writeReferenceChain() now bounded by a shared per-batch deadline with a drop counter, unvalidated referencechains sub-option values, a startThread()/ pthread_kill() race publishing _running before the thread handle is initialized, a null-JNIEnv leak in threadLoop(), releaseSearchTags() now surfacing GetObjectsWithTags() failures so restartSearch() never resets tag state prematurely, resolveLoadedClasses() skipping its per-class scan only when the loaded-class count is unchanged (not just non-decreasing), a spurious COMPLETED state after a failed first-pass FollowReferences call, and removal of a leftover debug helper in ExternalProcessReferenceChainTest. Adds regression test coverage for release-failure and negative-value option paths. Verified via the full ddprof-lib gtestDebug suite (149/149 tasks, 57/57 referenceChains_ut tests). Environment: Datadog workspace Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
1 parent 92c96d8 commit 9972bff

10 files changed

Lines changed: 580 additions & 173 deletions

File tree

ddprof-lib/src/main/cpp/arguments.cpp

Lines changed: 31 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
#include "arguments.h"
1919
#include "vmEntry.h"
2020

21+
#include <algorithm>
2122
#include <errno.h>
2223
#include <limits.h>
2324
#include <stdio.h>
@@ -473,18 +474,42 @@ Error Arguments::parse(const char *args) {
473474
char *eq = strchr(cursor, '=');
474475
if (eq) {
475476
*(eq++) = 0;
477+
// Floor every sub-option at the parse boundary rather than
478+
// trusting a downstream cast/clamp to make an operator-supplied
479+
// negative value safe: a negative hops value in particular gets
480+
// compared as `depth >= (u32)ctx->hop_cap` (referenceChains.cpp),
481+
// so an unclamped negative wraps to ~4e9 and silently disables
482+
// the hop cap entirely - the opposite of the flag's intent, and
483+
// it removes the one guard that otherwise bounds how long a
484+
// single reference chain (and therefore its
485+
// datadog.ReferenceChain JFR event) can grow. A negative budget
486+
// similarly collapses ReferenceChainTracker::_effective_budget
487+
// to 0 (updatePacing()'s own PID-clamp logic), which truncates
488+
// every pass immediately and leaves the search RUNNING
489+
// (re-walking the whole graph each cadence) until TTL instead of
490+
// making progress. A negative framecap is handed straight to
491+
// FrontierTable's constructor, which floors it to a
492+
// zero-capacity table (that class's own std::max(max_cap, 0)),
493+
// silently disabling tracking rather than erroring. ttl/
494+
// pausetarget/painbudget already have incidental downstream
495+
// clamps (runPass()'s `_ttl_ms > 0` gate, this class's own
496+
// PidController/PainBudget std::max(..., 0) calls) but are
497+
// floored here too so every sub-option's validation lives at one
498+
// boundary instead of being split between here and several
499+
// unrelated call sites.
476500
if (strcasecmp(cursor, "hops") == 0) {
477-
_reference_chains_hop_cap = atoi(eq);
501+
_reference_chains_hop_cap = std::max(atoi(eq), 1);
478502
} else if (strcasecmp(cursor, "budget") == 0) {
479-
_reference_chains_budget = atoi(eq);
503+
_reference_chains_budget = std::max(atoi(eq), 1);
480504
} else if (strcasecmp(cursor, "ttl") == 0) {
481-
_reference_chains_ttl_ms = atol(eq);
505+
_reference_chains_ttl_ms = std::max(atol(eq), 0L);
482506
} else if (strcasecmp(cursor, "framecap") == 0) {
483-
_reference_chains_frontier_cap = atoi(eq);
507+
_reference_chains_frontier_cap = std::max(atoi(eq), 1);
484508
} else if (strcasecmp(cursor, "pausetarget") == 0) {
485-
_reference_chains_pause_target_ms = atol(eq);
509+
_reference_chains_pause_target_ms = std::max(atol(eq), 0L);
486510
} else if (strcasecmp(cursor, "painbudget") == 0) {
487-
_reference_chains_pain_budget_percent = atoi(eq);
511+
_reference_chains_pain_budget_percent =
512+
std::min(std::max(atoi(eq), 0), 100);
488513
}
489514
}
490515
cursor = next;

ddprof-lib/src/main/cpp/counters.h

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -129,7 +129,18 @@
129129
* any dump() drained it - permanently lost, since _emitted_target_tags \
130130
* marks its tag as emitted the moment it is queued, not when it is \
131131
* actually written. See MAX_PENDING_CHAIN_EVENTS' own comment. */ \
132-
X(REFERENCE_CHAIN_EVENTS_DROPPED, "reference_chain_events_dropped")
132+
X(REFERENCE_CHAIN_EVENTS_DROPPED, "reference_chain_events_dropped") \
133+
/* ReferenceChainTracker::releaseSearchTags() (referenceChains.cpp) failed \
134+
* to call GetObjectsWithTags() for at least one batch - the search's tag \
135+
* release is retried on a later call rather than proceeding, but this \
136+
* counts how often that retry path is taken. */ \
137+
X(REFERENCE_CHAIN_TAG_RELEASE_FAILED, "reference_chain_tag_release_failed") \
138+
/* Profiler::writeReferenceChain() (profiler.cpp) could not acquire a \
139+
* sample-record lock within its bounded retry budget and dropped the \
140+
* already-dequeued datadog.ReferenceChain event - permanently lost, same \
141+
* as REFERENCE_CHAIN_EVENTS_DROPPED above but from the write side rather \
142+
* than the pending-queue side. */ \
143+
X(REFERENCE_CHAIN_WRITE_DROPPED, "reference_chain_write_dropped")
133144
#define X_ENUM(a, b) a,
134145
typedef enum CounterId : int {
135146
DD_COUNTER_TABLE(X_ENUM) DD_NUM_COUNTERS

ddprof-lib/src/main/cpp/flightRecorder.cpp

Lines changed: 29 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1949,19 +1949,43 @@ void Recording::recordHeapLiveObject(Buffer *buf, int tid, u64 call_trace_id,
19491949
}
19501950

19511951
void Recording::recordReferenceChain(Buffer *buf, ReferenceChainEvent *event) {
1952-
int start = buf->skip(1);
1952+
// event->_chain's length is bounded only by FrontierTable::maxCapacity()
1953+
// (tens of thousands of entries, referenceChains.h) - NOT by
1954+
// MAX_JFR_EVENT_SIZE, so this event cannot use writeEventSizePrefix()'s
1955+
// single-byte size field (its assert(size < MAX_JFR_EVENT_SIZE) is
1956+
// compiled out in release builds, making an oversize chain a silent
1957+
// corrupt size byte rather than a caught bug) nor rely on the trailing
1958+
// flushIfNeeded(buf) every fixed-size event above uses (that only flushes
1959+
// *after* already writing past the buffer). Truncate to
1960+
// MAX_REFERENCE_CHAIN_EVENT_HOPS (that constant's own comment) and
1961+
// reserve room for the truncated worst case up front instead.
1962+
u32 chain_size = (u32)event->_chain.size();
1963+
u32 emitted_size = chain_size < (u32)MAX_REFERENCE_CHAIN_EVENT_HOPS
1964+
? chain_size
1965+
: (u32)MAX_REFERENCE_CHAIN_EVENT_HOPS;
1966+
1967+
flushIfNeeded(
1968+
buf, RECORDING_BUFFER_LIMIT -
1969+
(MAX_VAR32_LENGTH /* multi-byte size prefix, below */ +
1970+
3 * MAX_VAR64_LENGTH /* type id, start_time, target_tag */ +
1971+
2 * MAX_VAR32_LENGTH /* depth, chain count */ +
1972+
(int)emitted_size * MAX_VAR32_LENGTH));
1973+
// Multi-byte size prefix (like writeDatadogSetting() above), not
1974+
// writeEventSizePrefix()'s single byte - this event's size can exceed
1975+
// MAX_JFR_EVENT_SIZE (255) once the chain is more than a few dozen hops.
1976+
int start = buf->skip(MAX_VAR32_LENGTH);
19531977
buf->putVar64(T_REFERENCE_CHAIN);
19541978
buf->putVar64(event->_start_time);
19551979
buf->putVar64(event->_target_tag);
19561980
buf->putVar32(event->_depth);
19571981
// T_CLASS array field (F_CPOOL|F_ARRAY, jfrMetadata.cpp) - each entry is a
19581982
// StringDictionary class id, same encoding as a scalar objectClass field
19591983
// (e.g. recordAllocation() above), just repeated `count` times.
1960-
buf->putVar32((u32)event->_chain.size());
1961-
for (u32 klass_id : event->_chain) {
1962-
buf->putVar32(klass_id);
1984+
buf->putVar32(emitted_size);
1985+
for (u32 i = 0; i < emitted_size; i++) {
1986+
buf->putVar32(event->_chain[i]);
19631987
}
1964-
writeEventSizePrefix(buf, start);
1988+
buf->putVar32(start, (u32)(buf->offset() - start));
19651989
flushIfNeeded(buf);
19661990
}
19671991

ddprof-lib/src/main/cpp/flightRecorder.h

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,20 @@ const int JFR_EVENT_FLUSH_THRESHOLD = RECORDING_BUFFER_LIMIT;
4040
const int MAX_VAR64_LENGTH = 10;
4141
const int MAX_VAR32_LENGTH = 5;
4242

43+
// Chain length Recording::recordReferenceChain() (flightRecorder.cpp) will
44+
// actually serialize per datadog.ReferenceChain event, independent of
45+
// ReferenceChainTracker's own _hop_cap/frontier-table cap - the frontier
46+
// table's own defensive walk bound (FrontierTable::reconstructChain(),
47+
// referenceChains.h) is maxCapacity(), which can run into the tens of
48+
// thousands of entries, and neither that cap nor _hop_cap is itself
49+
// range-validated against a buffer-safe maximum (see arguments.cpp's own
50+
// sub-option parsing). recordReferenceChain() truncates event->_chain to
51+
// this many entries before writing, so its own worst-case size never
52+
// depends on trusting either of those upstream caps to stay small - a chain
53+
// longer than this is still truncated defense-in-depth even if a caller
54+
// changes those caps later.
55+
const int MAX_REFERENCE_CHAIN_EVENT_HOPS = 4096;
56+
4357
#ifndef CONCURRENCY_LEVEL
4458
const int CONCURRENCY_LEVEL = 16;
4559
#endif

ddprof-lib/src/main/cpp/profiler.cpp

Lines changed: 35 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -809,37 +809,54 @@ void Profiler::writeReferenceChainAbandoned(ReferenceChainAbandonedEvent *event)
809809
// Unlike writeReferenceChainAbandoned() above (mirroring CPU/wall's signal-handler-safe
810810
// non-blocking pattern out of caution, even though its own call site - Profiler::dump(),
811811
// profiler.cpp - isn't a signal handler either), this call site genuinely cannot be one:
812-
// pollWatchedTargets() (referenceChains.cpp) only ever runs on ReferenceChainTracker's own
813-
// agent thread, never from a signal handler. A single bare 3-slot tryLock() sweep with no
814-
// wait - correct for a signal handler, which must never block - was found, by running
815-
// PROF-15341's end-to-end integration test
812+
// this is called from Profiler::dump()'s drain loop, on dump()'s own calling thread, once
813+
// per event drained from ReferenceChainTracker::_pending_chain_events (up to
814+
// MAX_PENDING_CHAIN_EVENTS per dump) - never from pollWatchedTargets() or any other call on
815+
// ReferenceChainTracker's own BFS agent thread, and never from a signal handler. A single
816+
// bare 3-slot tryLock() sweep with no wait - correct for a signal handler, which must never
817+
// block - was found, by running PROF-15341's end-to-end integration test
816818
// (ddprof-test's ReferenceChainTrackingTest.shouldReconstructReferrerChainToGcRoot) for real,
817819
// to drop this event under perfectly ordinary contention: the same _locks[] pool is shared
818820
// with every other sample type (recordJVMTISample() et al.), and any nontrivial allocation
819821
// throughput keeps enough of CONCURRENCY_LEVEL's slots busy that 3 immediate, back-to-back
820822
// attempts routinely all miss. A bounded retry with a short sleep between sweeps costs
821-
// nothing this thread cannot afford (it already sleeps for its own cadence, 10ms-4s between
822-
// passes, referenceChains.h's _effective_cadence_ns) and fixes the drop without touching the
823-
// signal-handler-safe call sites that must stay non-blocking.
824-
void Profiler::writeReferenceChain(ReferenceChainEvent *event) {
823+
// nothing the dump()-thread cannot afford, but the retry budget below is a single deadline
824+
// shared across the *entire* drain batch (see the caller in dump()) rather than per event:
825+
// with up to MAX_PENDING_CHAIN_EVENTS events queued, a fresh per-event budget could stall
826+
// the dump/JFR-flush thread for seconds under contention. Once the shared deadline has
827+
// passed this degrades to the same single non-blocking 3-slot sweep as
828+
// writeReferenceChainAbandoned() above for the remainder of the batch.
829+
void Profiler::writeReferenceChain(ReferenceChainEvent *event, u64 deadline_ns) {
825830
int tid = ProfiledThread::currentTid();
826831
if (tid < 0) {
827832
return;
828833
}
829-
const int kMaxLockAttempts = 50; // ~50ms worst case at 1ms/attempt - see comment above
830834
u32 lock_index;
831835
bool locked = false;
832-
for (int attempt = 0; attempt < kMaxLockAttempts; attempt++) {
836+
for (;;) {
833837
lock_index = getLockIndex(tid);
834838
if (_locks[lock_index].tryLock() ||
835839
_locks[lock_index = (lock_index + 1) % CONCURRENCY_LEVEL].tryLock() ||
836840
_locks[lock_index = (lock_index + 2) % CONCURRENCY_LEVEL].tryLock()) {
837841
locked = true;
838842
break;
839843
}
844+
if (OS::nanotime() >= deadline_ns) {
845+
// Shared batch budget exhausted - the sweep just above was already a
846+
// single non-blocking attempt, so stop retrying rather than sleeping
847+
// again.
848+
break;
849+
}
840850
usleep(1000);
841851
}
842852
if (!locked) {
853+
// Already dequeued from _pending_chain_events and its tag already
854+
// recorded in _emitted_target_tags (drainPendingChainEvents(), before
855+
// this call) - pollWatchedTargets() will never regenerate this event, so
856+
// the drop is permanent. Count it like every other counted-drop path
857+
// (REFERENCE_CHAIN_EVENTS_DROPPED's own comment) rather than dropping it
858+
// silently.
859+
Counters::increment(REFERENCE_CHAIN_WRITE_DROPPED);
843860
return;
844861
}
845862
_jfr.recordReferenceChain(lock_index, event);
@@ -1787,8 +1804,15 @@ Error Profiler::dump(const char *path, const int length) {
17871804
std::vector<ReferenceChainEvent> pending_chain_events;
17881805
ReferenceChainTracker::instance()->drainPendingChainEvents(
17891806
&pending_chain_events);
1807+
// One ~50ms retry budget for the *whole* batch, not per event -
1808+
// writeReferenceChain()'s own comment for why: up to
1809+
// MAX_PENDING_CHAIN_EVENTS events can be queued, and a fresh per-event
1810+
// budget would let this dump()-thread stall for seconds under ordinary
1811+
// _locks[] contention.
1812+
const u64 kChainDrainBudgetNs = 50 * 1000000ULL;
1813+
u64 chain_drain_deadline_ns = OS::nanotime() + kChainDrainBudgetNs;
17901814
for (auto &rc_event : pending_chain_events) {
1791-
writeReferenceChain(&rc_event);
1815+
writeReferenceChain(&rc_event, chain_drain_deadline_ns);
17921816
}
17931817

17941818
Libraries::instance()->refresh();

ddprof-lib/src/main/cpp/profiler.h

Lines changed: 9 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -433,16 +433,15 @@ class alignas(alignof(SpinLock)) Profiler {
433433
// the same way LivenessTracker::flush() is called from dump().
434434
void writeReferenceChainAbandoned(ReferenceChainAbandonedEvent *event);
435435
// Unlike writeReferenceChainAbandoned() above, this is NOT a bare 3-slot
436-
// tryLock() sweep - it retries with a bounded, sleeping loop (up to ~50ms
437-
// worst case) because its call site, ReferenceChainTracker::
438-
// pollWatchedTargets() (referenceChains.cpp), runs only on that tracker's
439-
// own agent thread and can tolerate blocking, unlike a signal handler; see
440-
// this method's own comment in profiler.cpp for why that retry exists.
441-
// Called for each chain event discovered this poll cycle, rather than from
442-
// dump() - see FlightRecorder::recordReferenceChain()'s own comment for why
443-
// chain events need their own call site instead of piggybacking on dump()'s
444-
// flush-on-dump pattern.
445-
void writeReferenceChain(ReferenceChainEvent *event);
436+
// tryLock() sweep - it retries with a bounded, sleeping loop because its
437+
// call site is dump()'s drain loop (profiler.cpp), on dump()'s own calling
438+
// thread, which can tolerate blocking, unlike a signal handler; see this
439+
// method's own comment in profiler.cpp for why that retry exists.
440+
// `deadline_ns` is a single retry budget shared across dump()'s *entire*
441+
// drain batch (not reset per event) - see the caller in dump() and this
442+
// method's own comment in profiler.cpp for why a per-event budget would be
443+
// unbounded across a large batch.
444+
void writeReferenceChain(ReferenceChainEvent *event, u64 deadline_ns);
446445
int eventMask() const { return _event_mask; }
447446
bool isRemoteSymbolication() const { return _remote_symbolication; }
448447

0 commit comments

Comments
 (0)