Qiita Teams that are logged in
You are not logged in to any team

Log in to Qiita Team
Community
OrganizationAdvent CalendarQiitadon (β)
Service
Qiita JobsQiita ZineQiita Blog
3
Help us understand the problem. What is going on with this article?
@notozeki

【Rails】ログにDeviseのユーザーIDを出力する

More than 1 year has passed since last update.

昨日に引き続き Devise ネタ。Rails で、ログに Devise のユーザーIDを出力する方法をまとめる。

なるべくシンプルに、素の Rails の機能だけを使って実現する。追加ライブラリ、カスタム logger や Rack ミドルウェアは不要:muscle:

以下のバージョンで動作を確認している。

  • Rails 6.0.2.1
  • Devise 4.7.1

TL;DR

以下のようなコードで、

config/environments/development.rb
  config.log_tags = [
    ->(req) {
      session_key = (Rails.application.config.session_options || {})[:key]
      session_data = req.cookie_jar.encrypted[session_key] || {}

      users = []
      %w(user admin).each do |scope| # user, admin はスコープの一例
        user_id = session_data.dig("warden.user.#{scope}.key", 0, 0)
        users << "#{scope}:#{user_id}" if user_id
      end

      users.join(',')
    }
  ]

以下のように、ログに Devise のログインユーザーのIDを記録できるようになる(先頭の [] の中)。

[user:1,admin:2] Completed 200 OK in 147ms (Views: 99.7ms | ActiveRecord: 8.3ms | Allocations: 15413)

背景

素の Rails には、ユーザー認証の仕組みは入っていないので、Devise などのライブラリを使って対応することが多い。

今回も、Devise を用いてユーザー認証を実装する機会があった。加えて、ログに「誰が操作したのか(ユーザーID)」を記録したいという要件があった。よくありそうなユースケースのわりに、あまり参考になる情報がなかったので、まとめておくことにした。

ログにlog_tagsで「タグ」をつける

Rails のログ設定の一つに log_tags というものがある。

config.log_tags: 次のリストを引数に取ります(requestオブジェクトが応答するメソッド、requestオブジェクトを受け取るProc、またはto_sに応答できるオブジェクト)。これは、ログの行にデバッグ情報をタグ付けする場合に便利です。たとえばサブドメインやリクエストidを指定することができ、これらはマルチユーザーのproductionアプリケーションをデバッグするのに便利です。
-- https://railsguides.jp/configuring.html#rails全般の設定

つまり、これを設定すると、ログの各行の頭に何かしらの出力(タグ)を追加できる。

よくあるのは、同一リクエストに対するログであることを識別するための「リクエストID」を出力する例である。たとえば、development.rb に↓のように書くと1

config/environments/development.rb
  config.log_tags = [ :request_id ]

↓のようなログ出力になる。

[424aabe4-63c2-4732-b566-fe04b97191ec] Started GET "/" for ::1 at 2020-01-31 11:35:26 +0900
[424aabe4-63c2-4732-b566-fe04b97191ec] Processing by StaticPagesController#index as HTML
[424aabe4-63c2-4732-b566-fe04b97191ec]   Rendering static_pages/index.html.erb within layouts/application
[424aabe4-63c2-4732-b566-fe04b97191ec]   Rendered static_pages/index.html.erb within layouts/application (Duration: 1.2ms | Allocations: 201)
[424aabe4-63c2-4732-b566-fe04b97191ec] [Webpacker] Everything's up-to-date. Nothing to do
[424aabe4-63c2-4732-b566-fe04b97191ec] Completed 200 OK in 76ms (Views: 67.3ms | ActiveRecord: 0.0ms | Allocations: 7674)

各行の先頭に付いている [424aabe4-63c2-4732-b566-fe04b97191ec] が、このリクエストのリクエストIDである。このように、ログの頭に [] で囲まれてタグが出るようになるのが log_tags の設定である。

Requestオブジェクトからセッション情報を取り出す

log_tagsProc オブジェクトを入れると、ActionDispatch::Request オブジェクトを引数としてその Proc を呼び出した結果が、タグとしてログに挿入される。

たとえば、以下のようにすると、

config/environments/development.rb
  config.log_tags = [ ->(req) { req.env['HTTP_USER_AGENT'] } ]

以下のようなログが出てくる。

[Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.130 Safari/537.36] Completed 200 OK in 57ms (Views: 49.8ms | ActiveRecord: 0.0ms | Allocations: 7428)

さて、この Request オブジェクトから Devise の認証情報が取れれば、それをタグに使うことができる。参考文献[1]によると、以下の方法でセッションデータが取れるらしい。

config/environments/development.rb
  config.log_tags = [
    ->(req) {
      session_key = (Rails.application.config.session_options || {})[:key]
      session_data = req.cookie_jar.encrypted[session_key] || {}
      session_data
    }
  ]

見てみる(一部省略)。

[{"session_id"=>"e4...", "warden.user.user.key"=>[[1], "$2a$11$fBAgejWzT9na6eZoIlYuP."], "warden.user.admin.key"=>[[2], "$2a$11$AXPU8A9xEASFrtZuFkwuVu"], "_csrf_token"=>"gc..."}] Completed 200 OK in 242ms (Views: 73.4ms | ActiveRecord: 77.8ms | Allocations: 11038)

works fine!!:thumbsup:

セッションの中身がすべて出力されているので少し長いが、以下のあたりにユーザー情報がありそうだ。

"warden.user.user.key"=>[[1], "$2a$11$fBAgejWzT9na6eZoIlYuP."], "warden.user.admin.key"=>[[2], "$2a$11$AXPU8A9xEASFrtZuFkwuVu"]

セッション情報からユーザーIDを特定

キーの"warden.user.xxxx.key"xxxxにあたるところが、Devise のスコープを表しているようだった。

値の方はなにやら不思議な形をしている。

[[1], "$2a$11$fBAgejWzT9na6eZoIlYuP."]

多分 1 がユーザーIDに対応するのかなと思ったが、やはりそのようだった。

参考: https://stackoverflow.com/questions/23597718/what-is-the-warden-data-in-a-rails-devise-session-composed-of

ただ、公式の情報はパッと調べた中では見つからなかった。なぜ[1]のように配列になっているのか気になったが、今回はそこまで深入りしない(ご存知の方がいれば教えてください:pray:)。

ともあれ、これで必要な情報は揃った。

ユーザーIDをログに出力する

フォーマットの検討

一般に Devise では複数の「スコープ」が扱える。たとえば UserAdmin を別々にログインできるようにする、というときにスコープを分けて対応する。

そのため、ログに記録すべきユーザーIDも User のものと Admin のものの2つ、というふうに複数になりえる。その前提で、ログのフォーマットを決める。

複数のユーザーIDを出力したときに、どのスコープのユーザーIDであるかを区別できるように、以下のようにスコープとIDを:で繋ぐことにして、

user:1

さらに、複数のスコープでログインしているときは、それらを,で繋ぐことにした。

user:1,admin:3

コード例

上記のフォーマットに従ってタグを整形するコードは以下のようになった。%w(user admin) のようなところは、そのプロジェクトで使っている Devise のスコープ名(単数形)に変える。

config/environments/development.rb
  config.log_tags = [
    ->(req) {
      session_key = (Rails.application.config.session_options || {})[:key]
      session_data = req.cookie_jar.encrypted[session_key] || {}

      users = []
      %w(user admin).each do |scope|
        user_id = session_data.dig("warden.user.#{scope}.key", 0, 0)
        users << "#{scope}:#{user_id}" if user_id
      end

      users.join(',')
    }
  ]

Hash#dig がラクで良い:relaxed:

この設定でログを出力すると、以下のようになった。

[user:1,admin:2] Completed 200 OK in 147ms (Views: 99.7ms | ActiveRecord: 8.3ms | Allocations: 15413)

LGTM:ok_woman:

本番環境でも使いたいときは config/environments/production.rb にも転記するのを忘れずに。

おまけ

ちなみに、Proc の戻り値が空文字列、つまりどのスコープでもログインしていないときは、タグ自体が出力されないようだった。空の [] が出力されるかと思ったが、ちゃんと空かどうか見ているようだ。

Completed 200 OK in 74ms (Views: 71.9ms | ActiveRecord: 0.0ms | Allocations: 4425)

参考文献


  1. ちなみに、production.rb ではデフォルトでこの設定になっている。 

3
Help us understand the problem. What is going on with this article?
Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
notozeki
Web技術とRubyが好きです。モバイルアプリやインフラも触るなんでも屋さん。お問い合わせなどはお気軽にTwitterやメールまでどうぞ。
5thfloor
Webシステムやモバイルアプリ開発、インフラ構築から運用監視までを幅広く。受託開発のほか、自社プロダクトとして創作・同人活動をサポートする「drill」「hondel」「ぷちのこ」などのサービスを開発・運営しています。

Comments

No comments
Sign up for free and join this conversation.
Sign Up
If you already have a Qiita account Login
3
Help us understand the problem. What is going on with this article?