はじめに

プロダクトの規模が大きくなってモデルのデータが変更される入口が増えてくると、

何の操作によってデータが変更されたのか？
何の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)

が特定できるようになりました！