Skip to content

Commit 5563ab9

Browse files
feat(traces): per-span limits and exception stacktraces (#955)
* feat(traces): per-span limits and exception stacktraces Bounds what one span can hold, per the traces spec. A span keeps at most max_attributes_per_span user attributes and max_events_per_span events (128 each, earliest-set wins), and each event at most 128 attributes; what the caps refuse is reported as droppedAttributesCount / droppedEventsCount, clamped to uint32. The posthogDistinctId and sessionId join keys are exempt. max_attribute_value_length (8192) bounds every string an attribute holds, nested ones included, along with span and event names, status messages and resource attributes, so one large value cannot get a span dropped as too large. Recorded exceptions now carry exception.stacktrace, keeping the tail of the traceback where Python puts the raising frame. Not reachable from the client. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TkZAsCciW4PV8ZdcCHmAbA * fix(traces): keep callables for the encoder's marker and stop charging None event attributes past the cap A callable was stringified by the value-length walk, so the OTLP encoder emitted its repr instead of the stable [Function] marker. And an event attribute bag with None past the per-event cap counted that None as a drop even though the encoder never emits it. * fix(traces): an empty attribute key spends no slot The encoder drops an empty key, so charging it against the cap lost a real attribute. Scalars skip the truncation walk, event attributes go through the shared copier so a non-mapping logs, and the traceback test is named for what it asserts: the outermost exception survives the cut. * fix(traces): guard span writes and end() with the handle's lock A same-key write from two threads could reserve two slots, and a write that lost the race to end() could land after the record was taken. The cap check, the event count and the end() snapshot now run under the handle's lock; the value walk still runs outside it. --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent 6786b5f commit 5563ab9

14 files changed

Lines changed: 1029 additions & 49 deletions

File tree

‎posthog/test/tracing/test_config.py‎

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,9 @@
11
import pytest
22

33
from posthog.tracing._config import (
4+
DEFAULT_MAX_ATTRIBUTE_VALUE_LENGTH,
5+
DEFAULT_MAX_ATTRIBUTES_PER_SPAN,
6+
DEFAULT_MAX_EVENTS_PER_SPAN,
47
DEFAULT_FLUSH_INTERVAL_SECONDS,
58
DEFAULT_MAX_EXPORT_BATCH_SIZE,
69
DEFAULT_MAX_LIVE_SPANS,
@@ -190,3 +193,39 @@ def __str__(self):
190193
assert resolved.service_name == "api"
191194
assert resolved.resource_attributes["team"] == "x"
192195
assert all(isinstance(key, str) for key in resolved.resource_attributes)
196+
197+
198+
class TestSpanLimitKnobs:
199+
def test_defaults_to_opentelemetrys_counts_and_a_finite_value_length(self):
200+
resolved = resolve_traces_config({})
201+
assert (
202+
resolved.max_attributes_per_span == DEFAULT_MAX_ATTRIBUTES_PER_SPAN == 128
203+
)
204+
assert resolved.max_events_per_span == DEFAULT_MAX_EVENTS_PER_SPAN == 128
205+
assert resolved.max_attribute_value_length == DEFAULT_MAX_ATTRIBUTE_VALUE_LENGTH
206+
assert DEFAULT_MAX_ATTRIBUTE_VALUE_LENGTH == 8192
207+
208+
def test_honours_explicit_values(self):
209+
resolved = resolve_traces_config(
210+
{
211+
"max_attributes_per_span": 10,
212+
"max_events_per_span": 5,
213+
"max_attribute_value_length": 100,
214+
}
215+
)
216+
assert resolved.max_attributes_per_span == 10
217+
assert resolved.max_events_per_span == 5
218+
assert resolved.max_attribute_value_length == 100
219+
220+
@pytest.mark.parametrize("value", [0, -1, 1.5, "128", None, True])
221+
def test_an_unusable_value_falls_back_rather_than_dropping_every_span(self, value):
222+
resolved = resolve_traces_config(
223+
{
224+
"max_attributes_per_span": value,
225+
"max_events_per_span": value,
226+
"max_attribute_value_length": value,
227+
}
228+
)
229+
assert resolved.max_attributes_per_span == DEFAULT_MAX_ATTRIBUTES_PER_SPAN
230+
assert resolved.max_events_per_span == DEFAULT_MAX_EVENTS_PER_SPAN
231+
assert resolved.max_attribute_value_length == DEFAULT_MAX_ATTRIBUTE_VALUE_LENGTH

‎posthog/test/tracing/test_export.py‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -950,6 +950,23 @@ def test_a_forked_child_drops_the_inherited_queue_and_timer(self):
950950
assert [r.name for r in queued(pipeline)] == ["child-span"]
951951

952952

953+
class TestResourceAttributes:
954+
def test_bounds_resource_attributes_on_every_batch(self):
955+
sender = FakeSender(SendOutcome("ok"))
956+
pipeline, _, _ = make_traces(
957+
sender=sender,
958+
max_attribute_value_length=5,
959+
resource_attributes={"team": "platform-infrastructure"},
960+
)
961+
pipeline.start_span("a").end()
962+
pipeline.flush()
963+
resource = {
964+
kv["key"]: kv["value"]
965+
for kv in sender.payloads[0]["resourceSpans"][0]["resource"]["attributes"]
966+
}
967+
assert resource["team"] == {"stringValue": "platf"}
968+
969+
953970
def waits_advance(clock, pipeline):
954971
"""Make the exporter's backoff wait move the fake clock instead of sleeping."""
955972
waited = []
Lines changed: 183 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,183 @@
1+
from unittest import mock
2+
3+
import pytest
4+
5+
from posthog.tracing import _limits as limits_module
6+
from posthog.tracing._limits import (
7+
bound_attributes,
8+
truncate_attribute_value,
9+
truncate_attributes,
10+
)
11+
from posthog.tracing._otlp import (
12+
CIRCULAR_VALUE,
13+
MAX_VALUE_ITEMS,
14+
MAX_VALUE_NODES,
15+
TRUNCATED_VALUE,
16+
to_any_value,
17+
)
18+
from posthog.tracing._sanitize import FUNCTION_VALUE, UNSERIALIZABLE_VALUE
19+
20+
21+
class TestTruncateAttributeValue:
22+
def test_truncates_a_long_string(self):
23+
assert truncate_attribute_value("x" * 40000, 8192) == "x" * 8192
24+
25+
def test_never_walks_a_scalar(self):
26+
with mock.patch.object(limits_module, "_truncate") as walk:
27+
assert truncate_attribute_value("short", 8) == "short"
28+
assert truncate_attribute_value(7, 8) == 7
29+
assert truncate_attribute_value(None, 8) is None
30+
assert not walk.called
31+
32+
def test_returns_a_short_string_unchanged(self):
33+
assert truncate_attribute_value("short", 8192) == "short"
34+
35+
@pytest.mark.parametrize("value", [42, 1.5, True, None, 2**70])
36+
def test_leaves_numbers_booleans_and_none_alone(self, value):
37+
assert truncate_attribute_value(value, 3) == value
38+
39+
def test_reaches_strings_nested_in_mappings_and_lists(self):
40+
value = {"body": "x" * 40000, "items": ["y" * 20, {"deep": "z" * 20}]}
41+
assert truncate_attribute_value(value, 8) == {
42+
"body": "x" * 8,
43+
"items": ["y" * 8, {"deep": "z" * 8}],
44+
}
45+
46+
def test_does_not_mutate_the_callers_value(self):
47+
value = {"body": "x" * 20}
48+
truncate_attribute_value(value, 4)
49+
assert value == {"body": "x" * 20}
50+
51+
def test_a_self_referencing_value_terminates_with_the_encoders_marker(self):
52+
value: dict = {"name": "n" * 20}
53+
value["self"] = value
54+
assert truncate_attribute_value(value, 4) == {
55+
"name": "nnnn",
56+
"self": CIRCULAR_VALUE,
57+
}
58+
59+
def test_siblings_sharing_one_object_are_not_a_cycle(self):
60+
shared = {"k": "v" * 10}
61+
assert truncate_attribute_value([shared, shared], 2) == [
62+
{"k": "vv"},
63+
{"k": "vv"},
64+
]
65+
66+
def test_marks_items_past_the_encoders_item_cap(self):
67+
bounded = truncate_attribute_value(["a"] * (MAX_VALUE_ITEMS + 5), 8)
68+
assert len(bounded) == MAX_VALUE_ITEMS + 1
69+
assert bounded[-1] == TRUNCATED_VALUE
70+
# The encoder emits the same shape it would have for the original.
71+
assert to_any_value(bounded) == to_any_value(["a"] * (MAX_VALUE_ITEMS + 5))
72+
73+
def test_stringifies_and_bounds_a_type_the_encoder_would_stringify(self):
74+
class Big:
75+
def __str__(self):
76+
return "b" * 100
77+
78+
assert truncate_attribute_value(Big(), 10) == "b" * 10
79+
assert truncate_attribute_value(b"\x00" * 100, 10) == "b'\\x00\\x00"
80+
81+
def test_a_key_the_encoder_skips_does_not_spend_the_walks_budget(self):
82+
# The encoder drops "" without charging for its value, so the walk must
83+
# too, or "x" would ship unbounded once the walk's budget ran out.
84+
value = {"": list(range(999)), "a": [list(range(999))] * 9, "x": "A" * 1000}
85+
bounded = truncate_attribute_value(value, 100)
86+
assert "" not in bounded
87+
assert bounded["x"] == "A" * 100
88+
encoded = to_any_value(bounded)["kvlistValue"]["values"]
89+
x = next(kv for kv in encoded if kv["key"] == "x")
90+
assert len(x["value"]["stringValue"]) == 100
91+
92+
def test_leaves_a_callable_for_the_encoders_marker(self):
93+
def handler():
94+
pass
95+
96+
assert truncate_attribute_value(handler, 3) is handler
97+
assert truncate_attribute_value({"fn": handler}, 3) == {"fn": handler}
98+
assert to_any_value(truncate_attribute_value(handler, 3)) == {
99+
"stringValue": FUNCTION_VALUE
100+
}
101+
102+
def test_a_raising_str_costs_only_that_value(self):
103+
class Hostile:
104+
def __str__(self):
105+
raise RuntimeError("no")
106+
107+
assert truncate_attribute_value({"a": Hostile(), "b": "ok"}, 8) == {
108+
"a": UNSERIALIZABLE_VALUE,
109+
"b": "ok",
110+
}
111+
112+
def test_a_raising_accessor_costs_only_that_key(self):
113+
class Explosive(dict):
114+
def __getitem__(self, key):
115+
if key == "bad":
116+
raise RuntimeError("no")
117+
return super().__getitem__(key)
118+
119+
assert truncate_attribute_value(Explosive(good="g" * 9, bad=1), 3) == {
120+
"good": "ggg",
121+
"bad": UNSERIALIZABLE_VALUE,
122+
}
123+
124+
125+
class TestBoundAttributes:
126+
def test_keeps_the_earliest_entries_and_counts_the_rest(self):
127+
source = {f"k{i}": i for i in range(130)}
128+
attributes, dropped = bound_attributes(source, 128, 8192)
129+
assert list(attributes) == [f"k{i}" for i in range(128)]
130+
assert dropped == 2
131+
132+
@pytest.mark.parametrize(
133+
"source",
134+
[{"a": None, "b": 1, "c": 2}, {"b": 1, "c": 2, "a": None}],
135+
ids=["before-the-cap", "past-the-cap"],
136+
)
137+
def test_a_none_value_spends_no_slot_and_counts_no_drop(self, source):
138+
attributes, dropped = bound_attributes(source, 2, 8)
139+
assert attributes == {"b": 1, "c": 2}
140+
assert dropped == 0
141+
142+
def test_a_real_value_past_the_cap_counts_a_drop(self):
143+
attributes, dropped = bound_attributes({"b": 1, "c": 2, "a": 3}, 2, 8)
144+
assert attributes == {"b": 1, "c": 2}
145+
assert dropped == 1
146+
147+
def test_bounds_each_value(self):
148+
attributes, _ = bound_attributes({"a": "x" * 20}, 2, 5)
149+
assert attributes == {"a": "xxxxx"}
150+
151+
def test_an_empty_key_spends_no_slot_and_counts_no_drop(self):
152+
attributes, dropped = bound_attributes({"": 1, "b": 2, "c": 3}, 2, 8)
153+
assert attributes == {"b": 2, "c": 3}
154+
assert dropped == 0
155+
156+
157+
class TestTruncateAttributes:
158+
def test_bounds_every_value_as_a_copy(self):
159+
source = {"service.name": "api", "blob": "x" * 20}
160+
assert truncate_attributes(source, 4) == {"service.name": "api", "blob": "xxxx"}
161+
assert source["blob"] == "x" * 20
162+
163+
164+
class TestWalkBounds:
165+
def test_walks_no_more_strings_than_the_encoder_would_emit(self):
166+
# A thousand paths to one shared list of a thousand strings. Leaves are
167+
# charged against the node budget, as in the encoder, so the walk does
168+
# not copy every string on every path.
169+
inner = ["x" * 50] * 1000
170+
bounded = truncate_attribute_value([inner] * 1000, 8)
171+
walked = sum(
172+
1
173+
for items in bounded
174+
if items is not inner
175+
for item in items
176+
if item == "x" * 8
177+
)
178+
assert 0 < walked <= MAX_VALUE_NODES
179+
180+
def test_stops_walking_a_mapping_at_the_encoders_item_cap(self):
181+
value = {f"k{i}": "v" * 50 for i in range(MAX_VALUE_ITEMS + 50)}
182+
bounded = truncate_attribute_value(value, 4)
183+
assert len(bounded) == MAX_VALUE_ITEMS

‎posthog/test/tracing/test_otlp.py‎

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -284,6 +284,39 @@ def test_marks_a_root_span_as_known_not_remote(self):
284284
def test_marks_a_header_parent_as_remote(self):
285285
assert build_otlp_span(record(parent_is_remote=True))["flags"] == 0x301
286286

287+
def test_omits_dropped_counts_when_nothing_was_dropped(self):
288+
span = build_otlp_span(record(events=[SpanEventRecord("e", START_NS)]))
289+
assert "droppedAttributesCount" not in span
290+
assert "droppedEventsCount" not in span
291+
assert "droppedAttributesCount" not in span["events"][0]
292+
293+
def test_emits_dropped_counts_on_the_span_and_its_events(self):
294+
span = build_otlp_span(
295+
record(
296+
dropped_attributes_count=2,
297+
dropped_events_count=3,
298+
events=[SpanEventRecord("e", START_NS, {"k": 1}, 4)],
299+
)
300+
)
301+
assert span["droppedAttributesCount"] == 2
302+
assert span["droppedEventsCount"] == 3
303+
assert span["events"][0]["droppedAttributesCount"] == 4
304+
305+
@pytest.mark.parametrize(
306+
"value,expected",
307+
[
308+
(2**40, 0xFFFFFFFF),
309+
(-1, 0),
310+
(1.9, 1),
311+
("3", 0),
312+
(True, 0),
313+
(float("inf"), 0),
314+
],
315+
)
316+
def test_clamps_a_dropped_count_to_uint32(self, value, expected):
317+
span = build_otlp_span(record(dropped_attributes_count=value))
318+
assert span.get("droppedAttributesCount", 0) == expected
319+
287320
def test_propagates_an_inbound_sampled_out_flag(self):
288321
assert build_otlp_span(record(trace_flags="00"))["flags"] == 0x100
289322

‎posthog/test/tracing/test_pipeline.py‎

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,14 +11,17 @@
1111
from posthog.test.tracing.helpers import (
1212
SPAN_ID,
1313
TRACE_ID,
14+
FakeSender,
1415
clock,
1516
fake_timers,
1617
make,
18+
make_traces,
1719
queued,
1820
)
1921
from posthog.tracing import _pipeline as pipeline_module
2022
from posthog.tracing import _span as span_module
2123
from posthog.tracing._drops import DropLog
24+
from posthog.tracing._transport import SendOutcome
2225
from posthog.tracing._span import NOOP_SPAN, PassThroughSpan, RecordingSpan
2326

2427
__all__ = ["clock", "fake_timers"]
@@ -414,6 +417,17 @@ def test_lets_user_attributes_win_on_collision(self):
414417
pipeline.start_span("a", attributes={"posthogDistinctId": "override"}).end()
415418
assert queued(pipeline)[0].attributes["posthogDistinctId"] == "override"
416419

420+
def test_the_join_keys_survive_a_span_at_its_attribute_cap(self):
421+
pipeline, _, _ = make(
422+
context={"distinct_id": "user-1", "session_id": "sess-1"},
423+
max_attributes_per_span=2,
424+
)
425+
pipeline.start_span("a", attributes={"x": 1, "y": 2, "z": 3}).end()
426+
record = queued(pipeline)[0]
427+
assert record.attributes["posthogDistinctId"] == "user-1"
428+
assert record.attributes["sessionId"] == "sess-1"
429+
assert record.dropped_attributes_count == 1
430+
417431
def test_still_records_the_span_when_reading_context_raises(self):
418432
pipeline, _, _ = make()
419433
pipeline._get_context = mock.Mock(side_effect=RuntimeError("no context"))
@@ -586,3 +600,29 @@ def test_reinit_after_fork_replaces_locks_without_acquiring_them(self):
586600
pipeline.reinit_after_fork()
587601
assert not pipeline._lock.locked()
588602
pipeline.start_span("a").end()
603+
604+
605+
class TestLimitsReachTheExport:
606+
def test_bounds_names_and_attributes_with_the_configured_length(self):
607+
sender = FakeSender(SendOutcome("ok"))
608+
pipeline, _, _ = make_traces(sender=sender, max_attribute_value_length=5)
609+
pipeline.start_span("a long name", attributes={"k": "a long value"}).end()
610+
pipeline.flush()
611+
(span,) = sender.batches()[0]
612+
assert span["name"] == "a lon"
613+
assert span["attributes"] == [{"key": "k", "value": {"stringValue": "a lon"}}]
614+
615+
def test_reports_a_spans_limit_drops_once_at_debug(self, caplog):
616+
caplog.set_level("DEBUG", logger="posthog")
617+
pipeline, _, _ = make(max_attributes_per_span=1, max_events_per_span=1)
618+
span = pipeline.start_span("capped", attributes={"a": 1, "b": 2})
619+
span.add_event("e1", {"k": 1}).add_event("e2")
620+
span.end()
621+
messages = [
622+
r.getMessage() for r in caplog.records if "Span limits" in r.getMessage()
623+
]
624+
assert len(messages) == 1
625+
assert messages[0].endswith(
626+
'Span limits discarded data from "capped": 1 attributes, 1 events, '
627+
"0 event attributes"
628+
)

0 commit comments

Comments
 (0)