Incompatible with Rails Tagged Logging :request_id

[pboling]

Error Class: NoMethodError Error Message:

undefined method `[]=' for nil:NilClass

Dies in ActionDispath::RequestId (Middleware) on line 28:

      @app.call(env).tap { |_status, headers, _body| headers[@header] = req.request_id }

The relevant portion of the backtrace is:

/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/middleware/request_id.rb:28:in `block in call'
<internal:kernel>:90:in `tap'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/middleware/request_id.rb:28:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.8/lib/rack/method_override.rb:24:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.8/lib/rack/runtime.rb:22:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/middleware/executor.rb:14:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/middleware/static.rb:25:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/rack-2.2.8/lib/rack/sendfile.rb:110:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/railties-7.1.3.2/lib/rails/engine.rb:536:in `call'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/rack-test-2.1.0/lib/rack/test.rb:360:in `process_request'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/rack-test-2.1.0/lib/rack/test.rb:153:in `request'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/testing/integration.rb:288:in `process'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/testing/integration.rb:22:in `post'
/Users/pboling/.asdf/installs/ruby/3.2.2/lib/ruby/gems/3.2.0/gems/actionpack-7.1.3.2/lib/action_dispatch/testing/integration.rb:379:in `post'

rodauth and rodauth-rails are not part of the backtrace, but this issue is only causing me trouble on my rodauth routes, and I'm thinking it is a rodauth-rails issue because rodauth core has nothing to do with rails.

Very possible that I've misidentified the issue. 🗡️ At the moment this is my best guess.

If it ends up being the case that there is an incompatibility, it would be awesome if we can figure out how to make it work, since having the a request id header forwarded through the whole app stack is incredibly powerful for diagnostics.

From the docs:

Action Dispatch RequestId Makes a unique request id available to the action_dispatch.request_id env variable (which is then accessible through ActionDispatch::Request#request_id or the alias ActionDispatch::Request#uuid) and sends the same id to the client via the X-ActionDispatch::Request-Id header. The unique request id is either based on the X-ActionDispatch::Request-Id header in the request, which would typically be generated by a firewall, load balancer, or the web server, or, if this header is not available, a random uuid. If the header is accepted from the outside world, we sanitize it to a max of 255 chars and alphanumeric and dashes only. The unique request id can be used to trace a request end-to-end and would typically end up being part of log files from multiple pieces of the stack.

[janko]

This indicates that a Rodauth route returned a rack response with no headers, violating the Rack spec, which would be very odd. What Rodauth route was this and what were the request parameters? I see from the stack trace that this happened in integration tests, does it happen in development as well? Can you reproduce it in the official demo app?

[pboling]

I'll see what I can come up with.

[pboling]

I think I have found the issue. Somehow, somewhere, I messed up my middleware stack, and at some point the @status, @headers, @response = @app.call(env) is returning the wrong stuff.

Thanks for your help!