Instrumenting async operations in Go

[albertteoh]

Please let me know if I should be asking this in another project/forum.

We came across a situation where a single request to an M3 endpoint resulted in two traces being created, when we expected a single trace. An example of traces resulting from a request to the query_range endpoint looks like the following and I've circled what I believe should be the continuation points of each trace:

I suspect the broken trace is caused by trace context being lost due to a the creation of a new Context within an async operation on this line of code: https://github.com/m3db/m3/blob/master/src/dbnode/client/host_queue.go#L879

I'm unfamiliar with instrumenting async operations and my questions are:

• Is this an instrumentation bug or a limitation of tracing instrumentation?
• If it's an instrumentation bug, what is the best way to deal with such a situation where context is lost in an async operation? I believe the motivation for creating the new context is the desire to reset the timeout. Perhaps the context should somehow be passed into the payload of the queue items and use a FollowsFrom relation?
  • Are there good Go examples of instrumenting async operations I can refer to?

[jpkrohling]

Async is typically a problem in other languages when using a facility like obtaining the "current span". In Go, the context is explicitly passed down, so, async operations should just work. In your specific case, the context is not being propagated, so, being async isn't really relevant to the situation. Can you somehow add context values to this Thrift context? Or start the Thrift context based on your existing context?

[yurishkuro]

We often ran into this issue at Uber and had a util method for copying the context, which uses SpanFromContext etc. to copy the span. thrift.NewContext is a tchannel function, it has a variant of doing the same from another ctx.

[albertteoh]

Thanks @jpkrohling @yurishkuro 🙏 Yes, I recall seeing thrift.NewContext back at Uber, now that you mention it :)

After looking a little deeper into the code, the async is implemented as an internal queue of "operations", and I think these operations' structs will need to be modified to store the original ctx prior to enqueuing, then upon dequing these "operations", use thrift.NewContext to derive a new context.