Propagate current trace context to Active Record async query threads #4543
Conversation
When leveraging Active Record's async query functionality (`load_async`, `async_count`, etc.), the queries are executed in a different thread, via concurrent-ruby's `ThreadPoolExecutor`. This causes the span for that query to not show up in the parent trace (often a `rack.request`). Now, the Active Record integration (for anything greater than v7.0.0) will wrap `ConnectionPool#build_async_executor` with the already-existing `ContextCompositeExecutorService` from the concurrent-ruby tracer integration, ensuring that the current trace is continued within the thread. Closes DataDog#3465.
|
|
||
| expect(spans).to include( | ||
| an_object_having_attributes(name: 'async_query.test', trace_id: root_trace.id), | ||
| an_object_having_attributes(name: 'pg.exec.params', trace_id: root_trace.id), |
There was a problem hiding this comment.
I ran into a very odd scenario here that led me to assert against pg.exec.params rather than postgres.query.
For reasons unknown to me, even with this patch, the sql.active_record Active Support notification does not seem to get tracked and converted into a DD span. I imagine this is due to a similar issue with the multi-threaded nature of the async query executor, but wasn't able to track it down in short order, so thought I would get this out and see if others had an idea!
| def patch | ||
| Events.subscribe! | ||
|
|
||
| if Integration.version >= Gem::Version.new('7.0.0') && ConcurrentRuby::Integration.patchable? |
There was a problem hiding this comment.
I would love to hear if this is the "right" way to leverage a different DD tracing integration. There is a bit of a weird interplay between Active Record and Concurrent Ruby, so would love to hear if this is OK or if there is different preferred approach.
| Datadog.configuration.tracing[:active_record].reset! | ||
|
|
||
| Datadog.configure do |c| | ||
| c.tracing.instrument :concurrent_ruby |
There was a problem hiding this comment.
Strictly speaking, this isn't actually necessary, but similar to the weirdness I raised in #4543 (comment), the interaction between Active Record and Concurrent Ruby is a little odd.
|
@marcotc was just wondering if this was something you'd be able to take a look at when you get a chance. It would be great to get this into a release soon! 🤞🏻 |
|
@agrobbin, yes! It's pretty much what I've been doing in the last two weeks 😅: #4872 It required quite a major change in how we flush traces and track background threads (which is a bug that greatly affects the concurrent-ruby instrumentation). More specifically, this didn't work correctly: dd-trace-rb/spec/datadog/tracing/tracer_spec.rb Lines 993 to 1001 in 44947b2 span-1 finished the whole wrapping trace would finish, and span-2 would create a new trace as a fallback that was not associated with the digest.This affects async queries because multiple queries can run in the background for a single load_async, depending on the DB adapter, and those would create new, unrelated traces in the background.
I still need to to fix all failing tests, and add new tests to ensure I didn't break basic span flushing. |
|
Ohh, wow, way more complicated than I thought! Looking forward to seeing all of that work land. 🎉 |
3 participants
What does this PR do?
The Active Record integration (for anything greater than v7.0.0) will now wrap
ConnectionPool#build_async_executorwith the already-existingContextCompositeExecutorServicefrom the concurrent-ruby tracer integration, ensuring that the current trace is continued within the thread.Closes #3465.
Motivation:
When leveraging Active Record's async query functionality (
load_async,async_count, etc.), the queries are executed in a different thread, via concurrent-ruby'sThreadPoolExecutor. This causes the span for that query to not show up in the parent trace (often arack.request).How to test the change?
I included tests here, but am definitely open to other approaches here!