Skip to content

Commit 66da54f

Browse files
committed
feat(runtime): Add pauseMs and runCount metrics to runtime
Signed-off-by: Cagri Yonca <cagri@ibm.com>
1 parent 36300ec commit 66da54f

2 files changed

Lines changed: 154 additions & 13 deletions

File tree

src/instana/collector/helpers/runtime.py

Lines changed: 77 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -1,16 +1,18 @@
1-
# (c) Copyright IBM Corp. 2021
1+
# (c) Copyright IBM Corp. 2021, 2026
22
# (c) Copyright Instana Inc. 2020
33

44
"""Collection helper for the Python runtime"""
55

6+
import contextlib
67
import gc
78
import importlib.metadata
89
import os
910
import platform
1011
import sys
1112
import threading
13+
import time
1214
from types import ModuleType
13-
from typing import Any, Callable, Dict, List, Union
15+
from typing import Any, Callable, Union
1416

1517
from instana.collector.base import BaseCollector
1618
from instana.collector.helpers.base import BaseHelper
@@ -49,7 +51,16 @@ def __init__(
4951
else:
5052
self.previous_gc_count = None
5153

52-
def collect_metrics(self, **kwargs: Dict[str, Any]) -> List[Dict[str, Any]]:
54+
# GC pause accumulators — flushed on every _collect_gc_metrics() call.
55+
# Populated by _gc_callback() via gc.callbacks (Python 3.3+).
56+
self._gc_start_times = {}
57+
self._gc_pause_total_ms = 0.0
58+
self._gc_run_count = 0
59+
60+
if gc.isenabled():
61+
gc.callbacks.append(self._gc_callback)
62+
63+
def collect_metrics(self, with_snapshot: bool = False, **kwargs: object) -> list[dict[str, Any]]: # noqa: ARG002
5364
plugin_data = dict()
5465
try:
5566
plugin_data["name"] = "com.instana.plugin.python"
@@ -64,7 +75,6 @@ def collect_metrics(self, **kwargs: Dict[str, Any]) -> List[Dict[str, Any]]:
6475
else:
6576
plugin_data["data"]["pid"] = str(os.getpid())
6677

67-
with_snapshot = kwargs.get("with_snapshot", False)
6878
self._collect_runtime_metrics(plugin_data, with_snapshot)
6979

7080
if with_snapshot:
@@ -75,13 +85,14 @@ def collect_metrics(self, **kwargs: Dict[str, Any]) -> List[Dict[str, Any]]:
7585

7686
def _collect_runtime_metrics(
7787
self,
78-
plugin_data: Dict[str, Any],
88+
plugin_data: dict[str, Any],
7989
with_snapshot: bool,
8090
) -> None:
8191
if os.environ.get("INSTANA_DISABLE_METRICS_COLLECTION", False):
8292
return
8393

8494
""" Collect up and return the runtime metrics """
95+
rusage = self.previous_rusage
8596
try:
8697
rusage = get_resource_usage()
8798
if gc.isenabled():
@@ -230,7 +241,39 @@ def _collect_runtime_metrics(
230241
finally:
231242
self.previous_rusage = rusage
232243

233-
def _collect_gc_metrics(self, plugin_data, with_snapshot):
244+
def _gc_callback(self, phase: str, info: dict[str, Any]) -> None:
245+
"""Accumulate GC pause time and run count via gc.callbacks.
246+
247+
Called by CPython twice per GC cycle: once with phase='start' and once
248+
with phase='stop'. Only primitive operations are performed here — no
249+
new Python objects are allocated — so the callback cannot trigger
250+
additional GC cycles.
251+
"""
252+
generation = info["generation"]
253+
if phase == "start":
254+
self._gc_start_times[generation] = time.perf_counter()
255+
elif phase == "stop" and generation in self._gc_start_times:
256+
elapsed_ms = (
257+
time.perf_counter() - self._gc_start_times.pop(generation)
258+
) * 1000
259+
self._gc_pause_total_ms += elapsed_ms
260+
self._gc_run_count += 1
261+
262+
def close(self) -> None:
263+
"""Remove the GC callback registered in __init__.
264+
265+
Must be called when the helper is torn down (agent reconnect, test
266+
teardown) to prevent stale callbacks accumulating in gc.callbacks,
267+
which is a process-level list.
268+
"""
269+
with contextlib.suppress(ValueError):
270+
gc.callbacks.remove(self._gc_callback)
271+
272+
def _collect_gc_metrics(
273+
self,
274+
plugin_data: dict[str, Any],
275+
with_snapshot: bool,
276+
) -> None:
234277
try:
235278
gc_count = gc.get_count()
236279
gc_threshold = gc.get_threshold()
@@ -278,12 +321,35 @@ def _collect_gc_metrics(self, plugin_data, with_snapshot):
278321
"threshold2",
279322
with_snapshot,
280323
)
324+
325+
# Flush accumulated pause metrics atomically: copy to locals first
326+
# so any GC cycle firing between read and reset is attributed to
327+
# the next window rather than being lost.
328+
pause_ms = self._gc_pause_total_ms
329+
run_count = self._gc_run_count
330+
self._gc_pause_total_ms = 0.0
331+
self._gc_run_count = 0
332+
333+
self.apply_delta(
334+
pause_ms,
335+
self.previous["data"]["metrics"]["gc"],
336+
plugin_data["data"]["metrics"]["gc"],
337+
"pauseMs",
338+
with_snapshot,
339+
)
340+
self.apply_delta(
341+
run_count,
342+
self.previous["data"]["metrics"]["gc"],
343+
plugin_data["data"]["metrics"]["gc"],
344+
"runCount",
345+
with_snapshot,
346+
)
281347
except Exception:
282348
logger.debug("_collect_gc_metrics", exc_info=True)
283349

284350
def _collect_thread_metrics(
285351
self,
286-
plugin_data: Dict[str, Any],
352+
plugin_data: dict[str, Any],
287353
with_snapshot: bool,
288354
) -> None:
289355
try:
@@ -321,7 +387,7 @@ def _collect_thread_metrics(
321387

322388
def _collect_runtime_snapshot(
323389
self,
324-
plugin_data: Dict[str, Any],
390+
plugin_data: dict[str, Any],
325391
) -> None:
326392
"""Gathers Python specific Snapshot information for this process"""
327393
snapshot_payload = {}
@@ -359,7 +425,7 @@ def _collect_runtime_snapshot(
359425

360426
plugin_data["data"]["snapshot"] = snapshot_payload
361427

362-
def gather_python_packages(self) -> Dict[str, Any]:
428+
def gather_python_packages(self) -> dict[str, Any]:
363429
"""Collect up the list of modules in use"""
364430
if os.environ.get("INSTANA_DISABLE_PYTHON_PACKAGE_COLLECTION"):
365431
return {"instana": VERSION}
@@ -408,7 +474,7 @@ def gather_python_packages(self) -> Dict[str, Any]:
408474

409475
def jsonable(
410476
self,
411-
value: Union[Callable[[], Any], ModuleType, Any],
477+
value: Union[Callable[[], str], ModuleType, object],
412478
) -> str:
413479
try:
414480
if callable(value):
@@ -423,3 +489,4 @@ def jsonable(
423489
return str(result)
424490
except Exception:
425491
logger.debug("jsonable: ", exc_info=True)
492+
return ""

tests/collector/helpers/test_collector_runtime.py

Lines changed: 77 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -20,14 +20,18 @@ def _resource(self) -> Generator[None, None, None]:
2020
),
2121
)
2222
yield
23+
self.helper.close()
2324
self.helper = None
2425

2526
def test_default_while_gc_disabled(self) -> None:
2627
import gc
2728

2829
gc.disable()
29-
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
30-
assert helper.previous_gc_count is None
30+
try:
31+
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
32+
assert helper.previous_gc_count is None
33+
finally:
34+
gc.enable()
3135

3236
def test_collect_metrics(self) -> None:
3337
response = self.helper.collect_metrics()
@@ -66,7 +70,77 @@ def test_collect_gc_metrics(self) -> None:
6670
plugin_data = self.helper.collect_metrics()
6771

6872
self.helper._collect_gc_metrics(plugin_data[0], True)
69-
assert len(self.helper.previous["data"]["metrics"]["gc"]) == 6
73+
assert len(self.helper.previous["data"]["metrics"]["gc"]) == 8
74+
75+
def test_gc_callback_registered(self) -> None:
76+
import gc
77+
78+
gc.enable()
79+
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
80+
try:
81+
assert helper._gc_callback in gc.callbacks
82+
finally:
83+
helper.close()
84+
85+
def test_gc_callback_removed_on_close(self) -> None:
86+
import gc
87+
88+
gc.enable()
89+
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
90+
helper.close()
91+
assert helper._gc_callback not in gc.callbacks
92+
93+
def test_gc_callback_not_registered_when_gc_disabled(self) -> None:
94+
import gc
95+
96+
gc.disable()
97+
try:
98+
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
99+
assert helper._gc_callback not in gc.callbacks
100+
finally:
101+
gc.enable()
102+
103+
def test_gc_callback_accumulates_pause(self) -> None:
104+
import gc
105+
106+
gc.enable()
107+
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
108+
try:
109+
assert helper._gc_pause_total_ms == 0.0
110+
assert helper._gc_run_count == 0
111+
112+
# Simulate one complete GC cycle (gen-0)
113+
helper._gc_callback("start", {"generation": 0})
114+
helper._gc_callback("stop", {"generation": 0})
115+
116+
assert helper._gc_pause_total_ms > 0.0
117+
assert helper._gc_run_count == 1
118+
finally:
119+
helper.close()
120+
121+
def test_gc_callback_flushes_on_collect(self) -> None:
122+
import gc
123+
124+
gc.enable()
125+
helper = RuntimeHelper(collector=HostCollector(HostAgent()))
126+
try:
127+
# Simulate a GC pause before collection
128+
helper._gc_callback("start", {"generation": 0})
129+
helper._gc_callback("stop", {"generation": 0})
130+
assert helper._gc_run_count == 1
131+
132+
plugin_data = helper.collect_metrics()
133+
helper._collect_gc_metrics(plugin_data[0], True)
134+
135+
# Accumulators must be reset after flush
136+
assert helper._gc_pause_total_ms == 0.0
137+
assert helper._gc_run_count == 0
138+
139+
gc_data = plugin_data[0]["data"]["metrics"]["gc"]
140+
assert "pauseMs" in gc_data
141+
assert "runCount" in gc_data
142+
finally:
143+
helper.close()
70144

71145
def test_collect_runtime_metrics(self) -> None:
72146
"""Test that _collect_runtime_metrics properly collects metrics"""

0 commit comments

Comments
 (0)