Skip to content

Commit 8b3d607

Browse files
feat(profiling): surface native-heap partition arming via dogstatsd gauge + warning
The native-heap ownership-partition arming decision was only observable via a one-shot stdlib INFO log, which real deploys drop (structured JSON loggers filter ddtrace stdlib records) and pods/exec is RBAC-blocked, so armed=true|false could not be confirmed at runtime. Surface the decision two ways at service start (gated on native-heap being enabled, so the default majority of processes stay silent): - emit a dogstatsd gauge profiling.native_heap.partition_armed (1=armed, 0=not) via the canonical internal client; fail-safe if the client is unavailable - upgrade the existing INFO arming line to WARNING (same fields)
1 parent ba29a15 commit 8b3d607

2 files changed

Lines changed: 166 additions & 15 deletions

File tree

ddtrace/profiling/profiler.py

Lines changed: 53 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,16 @@
3434

3535
LOG = logging.getLogger(__name__)
3636

37+
# pymalloc's small-request threshold (see CPython Objects/obmalloc.c). Requests
38+
# larger than this are delegated to glibc malloc, where the native-heap gotter
39+
# owns them, so the in-process sampler skips them when the partition is armed.
40+
_NATIVE_HEAP_SIZE_THRESHOLD_BYTES = 512
41+
# Dogstatsd gauge surfacing the native-heap ownership-partition arming decision
42+
# (1=armed, 0=not). Structured JSON loggers in real deploys drop ddtrace stdlib
43+
# records and pods/exec is RBAC-blocked, so the log line alone is not always
44+
# observable; this gauge gives an out-of-band, queryable signal at service start.
45+
_NATIVE_HEAP_PARTITION_ARMED_METRIC = "profiling.native_heap.partition_armed"
46+
3747

3848
class Profiler(object):
3949
"""Run profiling while code is executed.
@@ -406,6 +416,30 @@ def _arm_native_heap(self) -> bool:
406416
LOG.debug("Failed to arm native heap profiling", exc_info=True)
407417
return False
408418

419+
def _emit_native_heap_partition_armed_gauge(self, armed: bool) -> None:
420+
"""Emit a one-shot dogstatsd gauge reporting the arming decision.
421+
422+
Value is 1 when the native-heap ownership partition is armed and 0
423+
otherwise. Uses the same internal dogstatsd client and agent URL the
424+
rest of ddtrace uses. Fail-safe: a missing or broken dogstatsd client
425+
must never break profiler startup, so any error is swallowed.
426+
"""
427+
try:
428+
from ddtrace.internal.dogstatsd import get_dogstatsd_client
429+
from ddtrace.internal.settings._agent import config as agent_config
430+
431+
client = get_dogstatsd_client(agent_config.dogstatsd_url)
432+
client.gauge(
433+
_NATIVE_HEAP_PARTITION_ARMED_METRIC,
434+
1 if armed else 0,
435+
tags=[
436+
"domains:OBJ_MEM",
437+
"size_threshold_bytes:%d" % _NATIVE_HEAP_SIZE_THRESHOLD_BYTES,
438+
],
439+
)
440+
except Exception:
441+
LOG.debug("Failed to emit native heap partition arming gauge", exc_info=True)
442+
409443
def _start_service(self) -> None:
410444
"""Start the profiler."""
411445
native_heap_armed: bool = self._arm_native_heap()
@@ -440,17 +474,25 @@ def _start_service(self) -> None:
440474
# gotter did not arm, the partition is off and the in-process sampler keeps
441475
# sampling all sizes (no behavior change).
442476
memalloc.set_native_heap_partition(native_heap_armed)
443-
# One-shot, unambiguous startup line reporting the arming/partition
444-
# decision so it can be verified from pod logs without DEBUG. Emitted
445-
# exactly once as the profiler starts (never per-sample). When
446-
# armed=false the size split is inactive and the in-process sampler
447-
# keeps sampling all sizes; the threshold is still reported as the
448-
# configured value for clarity.
449-
LOG.info(
450-
"native heap ownership partition: armed=%s size_threshold_bytes=%d domains=OBJ|MEM",
451-
native_heap_armed,
452-
512,
453-
)
477+
# Surface the arming/partition decision so Phase 2 A/B validation can
478+
# confirm armed=true|false at runtime. Gated on the feature being
479+
# enabled so we never spam the WARNING/metric for the (default) majority
480+
# of processes that don't use native-heap profiling. Emitted exactly
481+
# once as the profiler starts (never per-sample). When armed=false the
482+
# size split is inactive and the in-process sampler keeps sampling all
483+
# sizes; the threshold is still reported as the configured value for
484+
# clarity.
485+
if profiling_config.native_heap.enabled:
486+
# WARNING (not INFO) so it survives deploys whose structured JSON
487+
# loggers filter out ddtrace INFO records.
488+
LOG.warning(
489+
"native heap ownership partition: armed=%s size_threshold_bytes=%d domains=OBJ|MEM",
490+
native_heap_armed,
491+
_NATIVE_HEAP_SIZE_THRESHOLD_BYTES,
492+
)
493+
# Also surface the decision as a dogstatsd gauge (1=armed, 0=not) for
494+
# the deploys where even WARNING logs are unobservable.
495+
self._emit_native_heap_partition_armed_gauge(native_heap_armed)
454496
if native_heap_armed:
455497
LOG.debug(
456498
"Native heap profiling armed; in-process managed-heap (pymalloc OBJ/MEM) sampling "

tests/profiling/test_native_heap_gotter.py

Lines changed: 113 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,18 @@
4141
_GOTTER_TEST_HOOK_AVAILABLE = False
4242

4343

44+
def _only_arming_warning(err: str) -> bool:
45+
"""Allow the one-shot native-heap arming WARNING on stderr, nothing else.
46+
47+
Once native-heap profiling is enabled the arming decision is intentionally
48+
logged at WARNING (so it survives prod log filtering), which the subprocess
49+
harness would otherwise reject as unexpected stderr. Runs in the parent test
50+
process against the subprocess's decoded stderr.
51+
"""
52+
lines = [line for line in err.splitlines() if line.strip()]
53+
return all("native heap ownership partition:" in line for line in lines)
54+
55+
4456
@pytest.mark.skipif(sys.platform != "linux", reason="native heap gotter is Linux-only")
4557
@pytest.mark.subprocess
4658
def test_native_heap_gotter_smoke() -> None:
@@ -72,7 +84,7 @@ def test_native_heap_gotter_smoke() -> None:
7284
assert len(blobs) == 200
7385

7486

75-
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
87+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"), err=_only_arming_warning)
7688
def test_profiler_start_arms_native_heap_when_enabled() -> None:
7789
"""Starting the profiler with native heap enabled invokes the activator.
7890
@@ -124,7 +136,7 @@ def test_profiler_start_skips_native_heap_when_disabled() -> None:
124136
prof.stop(flush=False)
125137

126138

127-
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
139+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"), err=_only_arming_warning)
128140
def test_profiler_start_survives_native_heap_install_error() -> None:
129141
"""A failure while arming native heap profiling must not break the profiler.
130142
@@ -150,7 +162,7 @@ def test_profiler_start_survives_native_heap_install_error() -> None:
150162
prof.stop(flush=False)
151163

152164

153-
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
165+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"), err=_only_arming_warning)
154166
def test_profiler_keeps_managed_heap_when_native_heap_armed() -> None:
155167
"""Ownership partition (Phase 2 de-dup): the partition is by allocator domain.
156168
@@ -192,7 +204,7 @@ def test_profiler_keeps_managed_heap_when_native_heap_armed() -> None:
192204
prof.stop(flush=False)
193205

194206

195-
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
207+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"), err=_only_arming_warning)
196208
def test_profiler_keeps_managed_heap_when_gotter_not_installed() -> None:
197209
"""Fail-safe: if native heap is enabled but the gotter did NOT install
198210
(install() returned False), the in-process sampler must remain active so
@@ -221,6 +233,103 @@ def test_profiler_keeps_managed_heap_when_gotter_not_installed() -> None:
221233
prof.stop(flush=False)
222234

223235

236+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
237+
def test_profiler_start_emits_partition_armed_gauge_when_armed() -> None:
238+
"""Arming observability: when the gotter installs (armed=True), the profiler
239+
emits the ``profiling.native_heap.partition_armed`` gauge with value 1 and
240+
logs the arming decision at WARNING level.
241+
"""
242+
from unittest import mock
243+
244+
from ddtrace.internal.datadog.profiling import heap_gotter
245+
import ddtrace.internal.dogstatsd
246+
from ddtrace.internal.settings.profiling import config as profiling_config
247+
import ddtrace.profiling.profiler as profiler_mod
248+
249+
profiling_config.native_heap.enabled = True # pyright: ignore[reportAttributeAccessIssue]
250+
251+
client = mock.Mock()
252+
with mock.patch.object(heap_gotter, "install", return_value=True):
253+
with mock.patch.object(heap_gotter, "live_heap_enabled", return_value=False):
254+
with mock.patch.object(ddtrace.internal.dogstatsd, "get_dogstatsd_client", return_value=client):
255+
with mock.patch.object(profiler_mod.LOG, "warning") as warning:
256+
prof = profiler_mod.Profiler()
257+
prof.start()
258+
try:
259+
assert client.gauge.call_count == 1
260+
args, kwargs = client.gauge.call_args
261+
assert args[0] == "profiling.native_heap.partition_armed"
262+
assert args[1] == 1, "gauge value must be 1 when armed"
263+
tags = kwargs["tags"]
264+
assert "domains:OBJ_MEM" in tags
265+
assert "size_threshold_bytes:512" in tags
266+
267+
assert warning.called, "arming decision must be logged at WARNING"
268+
msg = warning.call_args[0][0]
269+
assert "native heap ownership partition" in msg
270+
assert warning.call_args[0][1] is True, "WARNING must report armed=True"
271+
finally:
272+
prof.stop(flush=False)
273+
274+
275+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
276+
def test_profiler_start_emits_partition_armed_gauge_zero_when_not_armed() -> None:
277+
"""Arming observability: when native heap is enabled but the gotter did NOT
278+
install (armed=False), the gauge is still emitted, with value 0.
279+
"""
280+
from unittest import mock
281+
282+
from ddtrace.internal.datadog.profiling import heap_gotter
283+
import ddtrace.internal.dogstatsd
284+
from ddtrace.internal.settings.profiling import config as profiling_config
285+
import ddtrace.profiling.profiler as profiler_mod
286+
287+
profiling_config.native_heap.enabled = True # pyright: ignore[reportAttributeAccessIssue]
288+
289+
client = mock.Mock()
290+
with mock.patch.object(heap_gotter, "install", return_value=False):
291+
with mock.patch.object(ddtrace.internal.dogstatsd, "get_dogstatsd_client", return_value=client):
292+
with mock.patch.object(profiler_mod.LOG, "warning") as warning:
293+
prof = profiler_mod.Profiler()
294+
prof.start()
295+
try:
296+
assert client.gauge.call_count == 1
297+
args, _ = client.gauge.call_args
298+
assert args[0] == "profiling.native_heap.partition_armed"
299+
assert args[1] == 0, "gauge value must be 0 when not armed"
300+
assert warning.called
301+
assert warning.call_args[0][1] is False, "WARNING must report armed=False"
302+
finally:
303+
prof.stop(flush=False)
304+
305+
306+
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"), err=_only_arming_warning)
307+
def test_profiler_start_survives_partition_armed_gauge_error() -> None:
308+
"""Fail-safe: a broken/unavailable dogstatsd client must never break arming
309+
or profiler startup.
310+
"""
311+
from unittest import mock
312+
313+
from ddtrace.internal.datadog.profiling import heap_gotter
314+
import ddtrace.internal.dogstatsd
315+
from ddtrace.internal.settings.profiling import config as profiling_config
316+
import ddtrace.profiling.profiler as profiler_mod
317+
318+
profiling_config.native_heap.enabled = True # pyright: ignore[reportAttributeAccessIssue]
319+
320+
with mock.patch.object(heap_gotter, "install", return_value=True):
321+
with mock.patch.object(heap_gotter, "live_heap_enabled", return_value=False):
322+
with mock.patch.object(
323+
ddtrace.internal.dogstatsd, "get_dogstatsd_client", side_effect=RuntimeError("no agent")
324+
):
325+
prof = profiler_mod.Profiler()
326+
prof.start() # must not raise
327+
try:
328+
assert prof.status.value == "running"
329+
finally:
330+
prof.stop(flush=False)
331+
332+
224333
@pytest.mark.subprocess(env=dict(DD_PROFILING_ENABLED="true"))
225334
def test_profiler_keeps_managed_heap_when_native_heap_disabled() -> None:
226335
"""With native heap disabled, the in-process memory collector runs unchanged

0 commit comments

Comments
 (0)