How to use Rails Current Attributes to track nginx (web server) and unicorn (app server) logs with X-Request-ID

Rails version confirmed to work

6.0.3.4

As a common story

In order to search the log of the web server such as Nginx and the log of the application server such as unicorn and puma with the same ID, X-Request-ID is put in the log of the application server. It is easy to do it with the config setting prepared in Rails in advance, but there are the following problems.

Tagged Logging issues

If you are using Tagged Logging, X-Request-ID will be assigned to the log if you uncomment the following settings in the config file. config.log_tags = [ :request_id ]

If the X-Request-ID is 123456789, the log will look like ↓.

[2020-11-XXT09:37:34+09:00] [123456789] some message 

However, Tagged Logging does not output the backtrace to the log when there is the following processing, for example.

def XXX
rescue StandardError => e  
  logger.error e
end

In that case, you can achieve the same thing by using CurrentAttributes implemented from Rails 5.2. Current Attributes There is a word request_id in Documentation, and you can imagine that such a use case is assumed.

Code example in the documentation

# app/models/current.rb
class Current < ActiveSupport::CurrentAttributes
  attribute :account, :user
  attribute :request_id, :user_agent, :ip_address

  resets { Time.zone = nil }

  def user=(user)
    super
    self.account = user.account
    Time.zone    = user.time_zone
  end
end

Implementation method

All you have to do is set the X-Request-ID to CurrentAttributes in middleware and output it in formatter.

Create a class that inherits ActiveSupport :: CurrentAttributes

app/models/current.rb

# frozen_string_literal: true

class Current < ActiveSupport::CurrentAttributes
  attribute :x_request_id
end

Set the value to the class created using middleware,

config/initializers/x_request_id.rb

require 'current_x_request_id'

Rails.application.config.middleware.insert_after ActionDispatch::RequestId, CurrentXRequestId

ActionDispatch :: RequestId sets X-Request-ID to env ['action_dispatch.request_id']

lib/current_x_request_id.rb

# frozen_string_literal: true

class CurrentXRequestId
  def initialize(app)
    @app = app
  end

  def call(env)
    Current.x_request_id = env['action_dispatch.request_id']
    @app.call(env)
  end
end

Then output it with formatter

lib/formatter.rb

    def call(severity, time, progname, msg)
        msg = msg2str(msg) #Parent class (Logger) to output backtrace::Formatter) method (msg2str) is used
        ~~~
        "request_id: #{Current.x_request_id} #{msg}"
        ~~~
    end

As a caveat

CurrentAttributes is a very powerful mechanism, but it seems that you need to carefully consider it when using it. Here is an example of a note.

A word of caution: It's easy to overdo a global singleton like Current and tangle your model as a result.
Current should only be used for a few, top-level globals, like account, user, and request details.
The attributes stuck in Current should be used by more or less all actions on all requests. If you start
sticking controller-specific attributes in there, you're going to create a mess.

deepl translator

Overdoing a global singleton like Current can result in model entanglement.
Current should only be used globally for a few top-level globals such as account, user, request details, etc.
Attributes fixed to Current should be used more or less in every action in every request. if
Pasting controller-specific attributes can be confusing.