Trace Rails controllers that short-circuit with before_action

[delner]

The Rails integration currently does not produce controller spans for Rails controllers that short-circuit themselves in a before_action clause e.g. head :no_content.

This is because tracing is injected at the Metal level, the base-most class for Rails controllers. However, when Base and API controllers inherit from Metal, they also include other modules such as Callbacks, which overlay the action functions we modified at the Metal level. When these functions are overridden at the child class level (e.g. Base, API), the behavior in Callbacks takes precedence over that of our own tracing module, despite the use of prepend.

The implementation proposed in the pull request moves the patching from Metal to Base and API, so as to move the tracing module further up the ancestor chain. In doing so, however, controllers which inherit directly from Metal will no longer receive tracing out-of-the-box. They would need to include Datadog::Contrib::Rails::ActionControllerPatch to receive tracing.

[brettlangdon]

however, controllers which inherit directly from Metal will no longer receive tracing out-of-the-box

Do we know how often people do this?

Anything we can do to make inheriting from Metal directly work out of the box as well?

Having no additional steps is always :+1:

[pawelchcki]

Looks good! Agree with Brett that its worth considering to keep supporting Metal out of the box in addition to overriding inside Base and API.

[delner]

@brettlangdon @pawelchcki I took a very hard look at this to try to come up with a way of patching Metal out of the box. But because of a number of compounding factors, including inheritance and Rails load ordering, it looks like we don't have a choice.

Essentially we have two goals in conflict with one another; we want to push our module higher in the ancestors stack to make sure it doesn't get overridden and missed (i.e. this issue.) We also simultaneously want to make sure it ends up in all Rails controllers automatically by adding it to the least-common-denominator, Metal, which pushes our module lower in the ancestors stack. But, the module cannot appear twice in the ancestors stack, otherwise double instrumentation will occur.

• If we only patch Metal out of the box, the original issue remains because of module precedence.
• If we only patch Base and API out of the box, the original issue is resolved but controllers using Metal directly will lose automatic tracing.
• If we patch Metal Base and API out of the box, we end up with double instrumentation.

The only possible way I could suggest we have our cake and eat it too is by turning the double instrumentation into distinct measurements, hence turning a "bug" into a usable feature. What I mean by this is if we patched Metal as rails.action_controller.metal, and Base and API as rails.action_controller, then we'd have two measurements that each represent different, interesting parts of the same controller action.

The pros of which would mean out of the box Metal, Base API controllers can be traced, rack.request could still be updated with a nicer resource name if a controller short circuits, and any other traced operations occurring in before_action/after_action would end up nested under a nicer new metal span instead of rack.request.

The cons are that it's a different way of representing Rails traces altogether; the average Rails application without any controller callbacks would now see two controller spans stacked in one another, which might at a glance appear redundant even if it fact it isn't. Altering how our Rails traces look isn't something I take lightly, but also not something we should consider immune to change either.

All things considered, I would probably recommend we add this additional span, since to me there are many more pros than cons. I will create a proof of concept in this PR to demonstrate this, and link a screenshot or two to demonstrate how it looks. If we like it, we can keep it, otherwise we can ditch it and go with the Base and API instrumentation only plan.

[brettlangdon]

@delner what you are suggesting makes sense.

How does this trace generally look? Are the two controller spans basically the exact same duration or does it show overhead from Base/API when you are using Metal?

[delner]

A basic Rails trace would become:

1. rack.request
2. rails.action_controller.metal (NEW)
3. rails.action_controller
4. rails.render_template

In the most minimal of applications, spans 2 and 3 are expected to be of comparable length. However, for applications that perform additional operations after routing and before executing the controller action (e.g. before_action callbacks, which are fairly common), these lengths will be different, as those operations would add child spans to the Metal span. Previously the spans for these additional operations would have attached themselves to the rack.request instead.

I will produce screenshots to verify this hypothesis, and show how this looks.

Overall I think by adding this additional span, we would more accurately represent Rails traces, and provide some additional surface area to which we could add future instrumentation of Rails controllers.

[pawelchcki]

I really like this approach you're suggesting @delner! I think it can give more visibility to issues/timings of before_hook actions.

[delner]

@pawelchcki Yup, apologize, this is definitely not ready yet. Needs tests and additional implementation. What code we have here will fix the issue, but the tests won't reflect that yet. I'll let you know when it's ready.

[ivoanjo]

@delner Since this is very outdated, shall we go ahead and close this PR for now?