rack.request span that are stopped in middleware or before action doesn't have resource set

[beauraF]

Hello everyone 👋

I'm opening a dedicated bug report following this discussion.

This has a significant impact on the monitoring and alerting systems implemented by our teams. Since these spans have no resources, it is not possible to infer a team from them. This broke the reporting of dashboard built by team, and also our custom code that set a service to a rack.request based on the resource.

I've already seen several teams remove before_action, by calling directly into the controller's action to workaround this behavior ; after often spending several hours before understanding this subtlety.

@delner you made a proposal in the initial discussion, is that's still the direction you want to go in?

---

Current behaviour
rack.request span that are stopped in middleware or before action doesn't have resource set

Expected behaviour
rack.request span that are stopped in before action have resource set. Middleware also?

Environment

• ddtrace version: 1.20.0
• Ruby version: 3.2.3

[lloeki]

Hey @beauraF about this:

you made a proposal in the initial discussion, is that's still the direction you want to go in?

are you referring to this?

In theory, this could be done at a routing level if we instrumented the routing behavior. That would always run before any controllers, but should be able to show a route name.

[beauraF]

Hello @lloeki 👋 Yes, I think so!

[lloeki]

our custom code that set a service to a rack.request based on the resource

That's interesting, does this mean you're overriding the rack.request span service name?

In theory, this could be done at a routing level if we instrumented the routing behavior

FYI it's becoming less of a theory now: we're working on adding routing information to the rack.request span. This was worked on before but reverted because of issues with Rails 7.1 so we're redoing it.

What the PR does is tag the composite (because of nested apps/engines and their intermediate resolvers) route, but the same hooking process could also get and tag the target of the last route as resolved by a route resolver, which you could peruse.

I've already seen several teams remove before_action, by calling directly into the controller's action to workaround this behavior

I'd argue that including before/after_action callbacks inside the controller span would be incorrect and misleading as they are not executed within the lifetime of the controller's action.

I can definitely see an argument for:

• having a span for each callback, which would allow to precisely and semantically identify which callback is responsible for whatever time is spent
• having a span for ActionController::Instrumentation#process_action itself, which encompasses action callbacks. In fact we have such a hook for AppSec for precisely this reason, because actions can be effectual and AppSec is designed to block before actions are taken.

This is probably not actionable for you right now, but does any of this sound useful to have for you in the future?

[beauraF]

our custom code that set a service to a rack.request based on the resource

That's interesting, does this mean you're overriding the rack.request span service name?

Yes, with a SpanProcessor. It allow us to split in datadog our monolith on several "services" with a clear team ownership.

It look something like that:

module Doctolib
  module Datadog
    module SpanProcessors
      class ServiceSpanProcessor
        ENGINE_REGEX = %r{\A/engines/(?<engine>\w+)/}.freeze
        TARGETS = %w[method.call rack.request resque.job].freeze

        def call(trace)
          trace.spans.each do |span|
            next if TARGETS.none? { |target| span.name == target }

            service = inferred_service_name_for(span)
            span.service = service if !service.nil?
          end

          trace
        end

        # ...
      end
    end
  end
end

In theory, this could be done at a routing level if we instrumented the routing behavior

FYI it's becoming less of a theory now: we're working on #3849 to the rack.request span. This was worked on before but reverted because of issues with Rails 7.1 so we're redoing it.

Ah, that's good news!

What the PR does is tag the composite (because of nested apps/engines and their intermediate resolvers) route, but the same hooking process could also get and tag the target of the last route as resolved by a route resolver, which you could peruse.

It would be awesome!

I've already seen several teams remove before_action, by calling directly into the controller's action to workaround this behavior

I'd argue that including before/after_action callbacks inside the controller span would be incorrect and misleading as they are not executed within the lifetime of the controller's action.

Kinda a grey area to me. I could agree with you for before/after_action that are defined at ApplicationController level, and act as a "middleware" and therefore often doesn't relate with team code or ownership. That's another story for the one used to DRY like the common:

class UsersController < ApplicationController
  before_action :set_user, only: %i[ show update destroy ]

  # ...
end

This is probably not actionable for you right now, but does any of this sound useful to have for you in the future?

Yes, clearly. A good part of our latency come from middleware and hooks. So we built some custom instrumentation to track middleware "in" and "out" and callbacks. I have a feature request open about that: #3483

Thanks for looking into all this @lloeki, much appreciated 🙏