add experimental tracing using a native event collector #4250
Conversation
Overall package sizeSelf size: 6.73 MB Dependency sizes
🤖 This report was automatically generated by heaviest-objects-in-the-universe |
BenchmarksBenchmark execution time: 2024-05-10 20:16:51 Comparing candidate commit 0ce5417 in PR branch Found 1 performance improvements and 0 performance regressions! Performance is the same for 259 metrics, 6 unstable metrics. scenario:plugin-graphql-with-depth-on-max-18
|
Codecov ReportAll modified and coverable lines are covered by tests ✅
Additional details and impacted files@@ Coverage Diff @@
## master #4250 +/- ##
===========================================
- Coverage 80.42% 45.19% -35.24%
===========================================
Files 3 89 +86
Lines 373 2518 +2145
Branches 33 33
===========================================
+ Hits 300 1138 +838
- Misses 73 1380 +1307 ☔ View full report in Codecov by Sentry. |
|
comments closed, LGTM 👍 |
| .filter(val => val) | ||
| .join(' ') | ||
|
|
||
| span.setTag(RESOURCE_NAME, resource) |
There was a problem hiding this comment.
Why is RESOURCE_NAME tag no longer added?
We're kinda-sorta using it here for establishing endpoint names to associate with profiles, although we can also compute the value from HTTP_METHOD and HTTP_ROUTE tags when RESOURCE_NAME isn't present.
There was a problem hiding this comment.
It's still set but later in the pipeline. At this point the resource name cannot be trusted anyway because we allow changing it up until the span is finished, which is often used by customers.
There was a problem hiding this comment.
Would it be possible to simply always use HTTP_METHOD and HTTP_ROUTE for profiling since the real resource name would already be ignored anyway even with the current code? (although it could be argued these also can be changed by a span hook, but at that point the profile would need to wait for the span to actually be finished before looking at the resource name)
rochdev
force-pushed
the
collector-beta
branch
2 times, most recently
from
39e4e9f
to
f44dbab
Compare
| const ticks = finishTime | ||
| ? now() + finishTime - trace.ticks - trace.startTime | ||
| : now() - trace.ticks |
There was a problem hiding this comment.
Can we do this on the collector side? Otherwise we need to keep the timing state in the library. I feel like it should be safe to just send a Date.now() in the start event and monotonic timestamps in each of the start and end, then compute the delta in the collector.
There was a problem hiding this comment.
That's basically what this is doing except that it does that at the trace level instead of the span level. This is for efficiency but also because it was otherwise causing intermittent slight drifts. It's also worth noting that the computation is only happening when a finish time if provided, otherwise it only sends the monotonic timestamp.
There was a problem hiding this comment.
In both cases though you're holding the trace.ticks value. I'm suggesting we should try to avoid holding that in the library if at all possible. And I'm not sure why there would be drift coming from the same process on the same machine between monotonic timestamps that both came from that same process. 🤔
There was a problem hiding this comment.
This is also an optimization so that for applications under high load that generate traces quickly the events only need to send <=32 bits for the ticks instead of constantly 64 bits.
It also means an easier to reason about floor for the ticks which would always be 0 for the segment. However, since the number is arbitrary anyway, that doesn't actually matter too much.
Basically, it seemed to me that adding a single subtraction operation didn't add enough complexity to justify going with the alternative that saves a subtraction but ends up sending a lot more data. With the current structure of events, the timestamp is basically otherwise the largest piece of data of an event. I even considered going with microseconds since nanoseconds are rarely (read: never) useful for tracing data.
There was a problem hiding this comment.
But you're trading an extra potential maximum of 32 bits of data over the wire for more than that held in process memory for the duration of that span. That adds up quickly when there are potentially hundreds of thousands of concurrent spans. Process memory is a lot more scarce than bandwidth.
More concerning to me though is that we need a place to store any data like this which is held in-process for the span duration. I'm trying to get us away from storing the big bag of data that is SpanContext, but things like this further entangle it.
There was a problem hiding this comment.
It's actually the opposite. It trades the memory that would otherwise be held in memory for every span because the data is buffered, to a single integer that is held only once for the whole segment. So this actually saves memory in-process, and also has the benefit of reducing bandwidth. You could argue it increases CPU usage a tiny bit by adding a subtraction, but that's minimal enough to justify the trade-off.
There was a problem hiding this comment.
I'm not clear in what way this is reducing memory. We're still holding data in the SpanContext and therefore holding the SpanContext, are we not? So don't we still have the same problem with holding this big bag of data that we've always had? 😕
There was a problem hiding this comment.
I still don't understand where the problem is. Correct me if I'm wrong, but these seem to be the 2 approaches we are discussing:
Option 1:
- Send timestamp and ticks for segment.
- Send raw ticks for the span.
Option 2:
- Send timestamp for segment.
- Send computed ticks for span.
For option 1, you end up having to always send 64bit values. For option 2, you often need less than 64bit since the values will start from 0 instead of the ticks when the segment started. So option 2 uses less memory, at the cost of slightly more CPU for a subtraction per span, but that is an extremely low cost, and would be offset anyway by the need to write less data to the buffer.
I don't understand how putting less data in the buffer is supposed to result in more memory? Can you clarify your calculation?
There was a problem hiding this comment.
Computed ticks requires holding additional data on the Span Context between all the captured points in the segment, while just using raw ticks everywhere does not. It also makes it more complicated to take a more stream-oriented approach with less segment buffering as the timestamp the computed ticks are in relation to changes and would therefore add additional complexity to translating them back to absolute timestamps for backend processing and frontend visualization.
There's not a whole lot of benefit to being event-based if we're going to just continue buffering all the data in-process anyway. We're just moving held memory around rather than actually getting it out of the process which is the whole point of wanting to go for an event model.
|
|
||
| let segmentId = 0 | ||
|
|
||
| class DatadogCollectorSpan extends DatadogSpan { |
There was a problem hiding this comment.
This sub-classing is rather difficult to follow. Can we not just put all this logic in-place in DatadogSpan and use channel.hasSubscribers to skip it? There's a lot of circular dependency between this and the parent class calling methods on this that makes it challenging to understand the flow. I feel like it'd be a lot easier to understand if it was done in the parent class instead, or even with plain functions called from the parent class. 🤔
There was a problem hiding this comment.
The idea was to isolate the logic to a separate class instead of mixing it with the existing logic. I could instead just put all the code in the same place but it seemed like it would be even more confusing. I felt like keeping them separate also makes it more obvious what is shared versus what isn't.
There was a problem hiding this comment.
It could be separate but as functions that are just called from the other. I feel like the flow would be a lot clearer that way. As a sub-class you have to do a lot of spelunking into the parent class to understand what is being called when. 😐
There was a problem hiding this comment.
The parent calling a protected method on the child is how most of the tracer works since it comes from an OpenTracing background and OT does that extensively, so I don't think it should be surprising to anyone reading the code.
With that said, I can change it if you really want, but I'm not sure of the best approach then. I don't necessarily want to do it in the same file, because one of the ideas here was to not load this code at all when it's not needed. Not doing this is currently a huge problem in the library especially for serverless, and I didn't want to exacerbate the issue. What approach would you suggest with that in mind?
There was a problem hiding this comment.
Not going to block on this one, just wanted to point out it's really hard to follow so it would be ideal if we could make it more coherent somehow.
One possibility to enable only loading when you need it is multiple layers of diagnostics channel. You could have the existing class publish events with subscribers that do the transformations these functions are doing and then publish the result to those collector channels. Not sure that would be any clearer, but it would enable optional loading.
We could also consider some sort of dependency injection type thing where we register export strategies on the tracer and the span class could just loop over registered strategies and call each. Then the flow goes in a more singular direction rather than this confusing circular dependency.
There was a problem hiding this comment.
These sound like great ideas to explore, but in my opinion are out of the scope of this PR. Internals are already loaded in various ways that can end up being hard to follow, and standardizing on a way to do this would be more beneficial than introducing yet another way to load things for this PR specifically.
There was a problem hiding this comment.
I'm more concerned that piling on more complexity will make it even harder to untangle in the future whenever we get to cleaning that up. The present existence of tech debt doesn't justify making more. 😅
|
|
||
| this._timer = clearTimeout(this._timer) | ||
|
|
||
| collector.send_events(data) |
There was a problem hiding this comment.
❓ is collector.send_events sync? Do we need a done callback then? Can't we just return? Or is this done to preserve the flush signature from other exporters?
What does this PR do?
Add experimental tracing using a native event collector that stores and processes traces outside of the application.
Motivation
This was previously just a proof-of-concept. The goal of this PR is to have at last something on the main branch with proper CI tests so that we stay compatible with the use of events.
Additional Notes