http.route tag causes exception when interacting with engine route path helpers

[agrobbin]

Current behaviour

Starting in v1.21 (I believe due to #3345), we've started seeing errors from ddtrace when using a route helper from an engine (in our case, Motor Admin) in our tests:

# routes
constraints subdomain: 'admin' do
  mount Motor::Admin => '/'
end

# test
get motor_admin.motor_path

In our test suite, we started getting this exception:

Error:
Admin::HomeTest#test_return_not_found_when_signed_in_as_a_non-admin:
NoMethodError: undefined method `[]' for an instance of ActionDispatch::Journey::Route
    .../ruby/3.3.0/lib/ruby/gems/3.3.0/gems/ddtrace-1.21.0/lib/datadog/tracing/contrib/rails/patcher.rb:18:in `find_routes'
    .../ruby/3.3.0/lib/ruby/gems/3.3.0/gems/actionpack-7.1.3.2/lib/action_dispatch/journey/router.rb:32:in `serve'
    .../ruby/3.3.0/lib/ruby/gems/3.3.0/gems/actionpack-7.1.3.2/lib/action_dispatch/routing/route_set.rb:882:in `call'

I hope this is enough to go on, but if there's additional info I can provide, definitely let me know!

Expected behaviour

Tests pass without exception from ddtrace.

Environment

• ddtrace version: v1.21.0
• Configuration block (Datadog.configure ...):
• Ruby version: v3.3.0
• Operating system: macOS Sonoma 14.4 and Ubuntu 22.04.1
• Relevant library versions: Rails v7.1.3.2

[lloeki]

Sorry to hear that!

Thanks for the minimal repro, that's super helpful. I will take a look today.

@agrobbin just in case, can you give me the motor-admin version in use so that I can zero in as quickly as possible on it?

[agrobbin]

Oh right, I should've included that! We're on the latest version, motor-admin v0.4.26.

[lloeki]

Here's the result of my analysis.

The issue comes from ActionDispatch::Journey::Router#find_routes called by ActionDispatch::Journey::Router#serve.

Inside serve, Rails 7.0 (down to 4.0) does:

def serve(req)
  find_routes(req).each do |match, parameters, route|

Which goes through all routes and produces a result:

          routes.map! { |r|
            match_data = r.path.match(path_info)
            path_parameters = {}
            match_data.names.each_with_index { |name, i|
              val = match_data[i + 1]
              path_parameters[name.to_sym] = Utils.unescape_uri(val) if val
            }
            [match_data, path_parameters, r]
          }

This result is iterated upon via the each. Inside its block there's a return:

    return [status, headers, body]
  end
  
  #...
end

This returns, while located inside the block, applies to serve. So when a match is found, return immediately, interrupting the block and unwinding the stack up straight to serve's end (and executing any ensure). It's a GOTO end-of-#serve.

Since find_routes is evaluated first and each is called later with the block, the hook we place can obtain find_routes return value and use it to compute route information to be tagged before the block's return has a chance to evaluate.

Rails 7.1 changed that serve method a bit, and it now calls find_routes by directly passing it a block, without calling each:

def serve(req)
  find_routes(req) do |match, parameters, route|

Now, instead of returning an enumerable of [match data, path_parameters, route] items, it yields each such item to the directly passed block:

routes.each { |r|
            match_data = r.path.match(path_info)
            path_parameters = {}
            match_data.names.each_with_index { |name, i|
              val = match_data[i + 1]
              path_parameters[name.to_sym] = Utils.unescape_uri(val) if val
            }
            yield [match_data, path_parameters, r]
          }

This makes the (slightly modified but essentially identical) return inside the passed block immediately effective.

    return response
  end
  
  # ...
end

Since find_routes's block is evaluated directly by a (sequence of) yield in routes.each:

• When a route is found, a GOTO end-of-serve is immediately performed. This immediately unwinds the stack through the routes.each block, routes.each itself, then find_route, then the hook's find_route, and finally jumps to the end of serve. Each stack unwinding step has the opportunity to call a hypothetical ensure block. All return values are nil except serve's which is response (but only the caller of serve will see that). Any code after the hook's super call is ignored.
• When no route is found, routes.each completes and since each returns its self find_routes's return value is now just routes. The hook, expecting an array of [match data, path_parameters, route], is not prepared for that return value, finds a Route instead, which causes the reported issue.

[lloeki]

AIUI in the provided repro it seems that get motor_admin.motor_path does not hit any route known to the router (maybe it's missing the /admin prefix?) and thus produces the reported exception.

In any case for Rails 7.1:

• the HTTP route tracing feature is not operational.
• the HTTP route tracing feature causes an exception on unmatched routes.

We are working on a fix and will attempt a hotfix release early next week (current plan is Tue).

[agrobbin]

@lloeki thanks so much for your detailed walkthrough of the issue! For what it's worth, we do have a matching route in our routing table here:

                         Prefix    Verb     URI Pattern             Controller#Action
# ...
                    motor_admin             /admin                  Motor::Admin
# ...
Routes for Motor::Admin:
# ...
                          motor    GET     /                        motor/ui#show
# ...

[simi]

ℹ️ same problem here - rubygems/rubygems.org#4537

[ivoanjo]

(We've merged a fix for this, and we're in the final validation steps before publishing a 1.21.1 release with the fix. Because a lot of folks seem to be bitten by this, I'll go ahead and reopen the issue until we actually put the release out so folks can easily find this ticket)

[TonyCTHsu]

@agrobbin @simi 1.21.1 has been released!

[simi]

@TonyCTHsu thanks for the info, fix seems super effective!

rubygems/rubygems.org#4548