feat: Avoid truncating span descriptions#782
Conversation
For database auto-instrumented spans, the description contains potentially long SQL queries that are most useful when not truncated. Because arbitrarily large events may be discarded by the server as a protection mechanism, we dynamically limit the description length, preserving the most important descriptions/queries. Performance impact Preliminary CPU profiling using [1] suggests that uuid4() dominates the execution time for code sending many transactions sequentially. Preliminary memory profiling using [2] and looking at the max RSS of a benchmark script suggests that the max RSS has no significant change (JSON encoding in CPython is implemented in C). In any case, we mitigate any increase in memory usage and run time for the majority of cases by avoiding any extra work when the total number of bytes consumed by descriptions do not exceed ~512 KB, which is equivalent to having the standard string truncation applied. Integrating profiling to the SDK is left for a future PR. [1]: https://pypi.org/project/zprofile/ [2]: /usr/bin/time -l (macOS)
untitaker
left a comment
untitaker
left a comment
There was a problem hiding this comment.
lgtm. if possible I would make this an _experiment flag for now, which we can then remove in the next 0.x version
| memo = Memo() | ||
| path = [] # type: List[Segment] | ||
| meta_stack = [] # type: List[Dict[str, Any]] | ||
| span_description_bytes = [] |
There was a problem hiding this comment.
I think this can be a simple integer, that would probably lower memory usage a tiny little bit. Since we don't have nonlocal you can still use a fixed-length list like this:
span_description_bytes[0] += value
instead of:
span_description_bytes.append(value)
There was a problem hiding this comment.
I've considered both; nonlocal is not an option in Python 2.7 and among list with single int or adhoc class with mutable field I thought list of lengths is the least surprising option. This piece of code is already super hard to read and understand, a list of ~999 ints vs list of one int makes no practical difference.
There was a problem hiding this comment.
I get the argument about readability but this is an extremely hot code path. Still you're right that this is unlikely to regress perf
Could you help me with that? I guess two if's around |
| span = event["spans"][i] | ||
| now = datetime.utcnow() | ||
| start = span.get("start_timestamp") or now | ||
| end = span.get("timestamp") or now |
There was a problem hiding this comment.
Is now the most correct here? How is it even possible these can be nil by the time we hit the serializer?
I assume if we get a span without a valid start_timestamp or timestamp we should disregard it right?
There was a problem hiding this comment.
It is there for the sake of defensive coding. Is it not the role of the serializer to validate spans.
Note that now is not used to update the span, only to compute a timedelta for sorting.
There was a problem hiding this comment.
For sure, I see that. Maybe this is out of scope for the PR, but I wonder if we can make the guarantee that the spans are valid before hit hits the serializer. That way we don't need the extra func call.
Also, if start gets now, and end uses it's timestamp, wouldn't you get a negative timedelta?
There was a problem hiding this comment.
Also, if
startgets now, andenduses it's timestamp, wouldn't you get a negative timedelta?
The original start and end timestamps could also give a negative duration. That will only affect the sort order.
3 participants
For database auto-instrumented spans, the description contains potentially long SQL queries that are most useful when not truncated.
Because arbitrarily large events may be discarded by the server as a protection mechanism, we dynamically limit the description length, preserving the most important descriptions/queries.
Performance impact
Preliminary CPU profiling using [1] suggests that uuid4() dominates the execution time for code sending many transactions sequentially.
Preliminary memory profiling using [2] and looking at the max RSS of a benchmark script suggests that the max RSS has no significant change (JSON encoding in CPython is implemented in C).
In any case, we mitigate any increase in memory usage and run time for the majority of cases by avoiding any extra work when the total number of bytes consumed by descriptions do not exceed ~512 KB, which is equivalent to having the standard string truncation applied.
Integrating profiling to the SDK is left for a future PR.
[1]: https://pypi.org/project/zprofile/
[2]:
/usr/bin/time -l(macOS)Related to getsentry/relay#674