はじめに
プロダクトの規模が大きくなってモデルのデータが変更される入口が増えてくると、
- 何の操作によってデータが変更されたのか？
- 何のController、Actionで変更がされたのか
- 変更された入口はどこなのか？
というのを特定し辛くなり、不具合やお問い合わせの調査に苦戦します。この記事ではauditsとDatadogを用いて上記問題が特定できるようになり調査が楽になりました。
※audits、Datadogの導入手順については省略します。
auditsとは
RailsのGemで、モデルの変更を監視してくれるライブラリです。
auditsテーブルには誰がその変更を行ったかを記録することができます。
使い方、導入
https://github.com/collectiveidea/audited
※コールバックが発生しない変更やactiverecord-importのようなbulk_insertではauditsにデータは残りませんので注意
auditsテーブルの内容(一部抜粋)
| カラム名 | 説明 |
|---|---|
| id | システム内ID |
| auditable_id | 監視先のテーブルのID |
| auditable_type | 監視先のモデル名 |
| user_id | 変更を行ったUserのID |
| action | 変更時のアクション名(update、create、destroyなど) |
| audited_changes | 変更内容 |
| request_uuid | リクエストのUUID(Datadogでどういう操作で変更されたのかを特定するのに使用) |
| created_at | 変更日時 |
Datadogについて
Datadogとはインフラ、アプリケーション、及びログを一元的に監視・分析するためのツールです。
https://docs.datadoghq.com/ja/containers/
この記事では主にDatadogのLogsにRailsアプリケーションのログを送信して調査することを前提にします。
RailsのログをDatadogに送信する
DatadogにRailsのログを送信する設定を行います。ドキュメント通りlogrageを使います。
https://docs.datadoghq.com/ja/logs/log_collection/ruby/?tab=lograge
1. Gemをインストールする
gem 'lograge'
2. Docker環境なのでビルドする
docker-compose build
docker-compose up -d
3. logrageの設定をする
app/controllers/application_controller.rb
# frozen_string_literal: true
class ApplicationController < ActionController::Base
private
def append_info_to_payload(payload)
super
payload[:login_user] = current_user&.id
payload[:ua] = request.user_agent
payload[:referer] = request.referer
payload[:remote_ip] = request.remote_ip
payload[:request_id] = request.uuid
end
end
config/initializers/lograge.rbを作成。下記内容を記述します。
Rails.application.configure do
if Rails.env.production? || Rails.env.staging?
config.lograge.enabled = true
config.lograge.formatter = Lograge::Formatters::Json.new
config.lograge.custom_options = lambda do |event|
{
ddtrace: 'rails',
env: Rails.env,
ddsource: ['app_name'],
login_user: event.payload[:login_user], # ユーザーIDが必要であれば
remote_ip: event.payload[:remote_ip],
ua: event.payload[:ua],
referer: event.payload[:referer],
controller: event.payload[:controller],
action: event.payload[:action],
params: event.payload[:params].except('controller', 'action').to_json,
method: event.payload[:method],
path: event.payload[:path],
status: event.payload[:status],
duration: event.duration,
time: Time.zone.now,
request_id: event.payload[:request_id]
}
end
end
end
4. ログの冒頭タグを外す
※ActiveSupport::TaggedLogging はログの頭に勝手にタグを付与するので、ログメッセージが JSON と見做されなくなってしまいます。
config/environments/production.rb
- config.log_tags = [ :request_id ]
- config.logger = ActiveSupport::TaggedLogging.logger(STDOUT)
+ config.logger = ActiveSupport::Logger.new(STDOUT)
※ステージング環境も同様に設定が必要であれば同様に設定をお願いします。
以上でDataDogにRailsのログを送信する準備が整いました。
DataDogのLogsに下記画像のようなデータが飛んでいることを確認して下さい。
調査手順
お客様より例えばあるデータが勝手に変わっているというお問い合わせを受けた際の手順を記載します。
1. auditsよりお問い合わせ内容のデータが変更されたレコードを特定します。
例えばあるユーザーのデータが書き換わっていたというお問い合わせを受けたとします。
下記のようなSQLで特定します。
SELECT
*
FROM
audits
WHERE
audits.auditable_id = 1
AND audits.auditable_type = 'User'
ORDER BY
created_at DESC
2. auditsのデータが表示されるので、audited_changesより変更内容を特定。該当のデータのrequest_uuidを控えます。
3. Datadog > Logsの検索窓に下記のように入力して検索します。
@request_id:<uuid>
4. 変更されたログを開きます。
ログより
- どの画面で(referer)
- どのController、Actionによって
- どの環境で(ua)
- どのユーザーが行ったのか(login_user)
が特定できるようになりました！