こんにちわ
9/7 ~ 9/25 の期間でアカツキのAkatsuki Summer Internship 2020に参加してきました
この記事ではインターン中に取り組んだ内容について紹介したいと思います。
3週間お世話になりますっ pic.twitter.com/vGG7733ABi
— さんぽし (@sanpo_shiho) September 7, 2020
インターン業務内容
今回のインターンでは「ログ配信周りの改善」を中心とする以下のタスクを行いました。
- 開発環境からログの配信を行えるようにする
- アクセスログの配信方法の改善
- Redash にて Athena からアクセスログの解析
既存のログ配信環境に関して
既存のログ配信の構成は以下のようになっていました
- app コンテナがアクセスログをアプリケーションログ内に吐く
- Volume を通して fluentd が tail する形でアクセスログのみを収集、また KPI 分析などの特別な目的で利用する情報は別途直接 fluentd に送られる
- fluentd はログを分類し、アクセスログは直接複数の S3 へ、KPI ログなどは Aggregator に配信
- Aggregator はさらにそれを複数の RDS や S3 に対して配信
という流れになっています。
開発環境からログの配信
プロジェクトにはローカルに立ち上げることができる開発/検証用の環境が存在しています。 既存では docker-compose を利用して app・MySQL・Redis・memcached が立ち上がるようになっていました。
※ログ配信に関係のない Redis, memcached を省略
現状の問題点として、ここにログ配信周りの環境が含まれていないことにより、
- ログの出力に関わる開発を行った際に KPI ログなどが行き着く先の RDS の型などの検証ができない
- 今回僕がやるような fluentd 自体を絡めた開発の検証ができない
と言った点がありました
そこで環境に fluentd のコンテナを新たに追加し、アプリケーションから手元の fluentd を通して開発用 S3 へログを配信する変更を加えました。
ざっくり変更後の検証環境の構成図です
※ログ配信に関係のない Redis, memcached を省略
また、図にあるように、すでに存在する MySQL に KPI ログの記録用の DB を作成し、RDS に投げ込まれるログをこの環境では MySQL に向けることで RDS を絡めた開発の検証にも対応しました。
ちなみに、S3 への Upload を行う際の認証はshared_credentialsのオプションを利用し、手元の~/.aws/credentialsをコンテナ内にマウントすることで行いました。
アクセスログの配信方法の改善
アクセスログの既存の配信方法は
- アプリケーションコンテナがファイルにアクセスログを吐く
- volume を通して fluentd コンテナが tail する
- fluentd でアクセスログのみをうまく grep して抽出し、S3 などに配信する
と言った仕組みになっています。
これによる問題点として以下のような点があります。
- 同時に膨大な数のアプリケーションコンテナが同一のログファイルに書き込むためなのかごく稀にログが壊れている
- fluentd にてアプリケーションログからアクセスログのみを grep するのが非効率 and 稀に不正確
改善策としてはシンプルに forward している fluentd に対して KPI ログなどとは別のポートを通して直接ログを送りつける形に変更しました。
以下変更後の構成図です
既存のアクセスログの出力には lograge を利用していました
アクセスログに求められる要件は以下の通りです
- 既存の lograge が出しているログの内容はそのまま欲しい
- アプリケーションログファイルへのアクセスログの出力は残しておきたい
- 500 が帰った際などの exception など追加で欲しい情報がある。また、POST パラメータを JSON シリアライズしたいなど、lograge の内容から少しカスタマイズをかけたい
lograge の logger として fluentd への出力を行うact-fluent-logger-railsなどの logger を登録するというのがシンプルな方法だったのですが、lograge の logger は複数設定できず、アプリケーションログファイルに残しつつ fluentd へ log を出力するという要件を満たせませんでした
そのため、lograge はそのままアプリケーションログへの出力を担当させておき、上記の要件をみたすログを fluentd へと送る部分の開発を行いました
この開発には以下の Active Support::Notifications を利用しました
Active Support は Rails のコア機能のひとつであり、Ruby 言語の拡張、ユーティリティなどを提供するものです。Active Support に含まれている Instrumentation API は、Ruby コードで発生する特定の動作の計測に利用できます。
イベントは簡単にサブスクライブできます。ActiveSupport::Notifications.subscribe をブロック付きで 記述すれば、すべての通知をリッスンできます。
Active Support の Instrumentation 機能 - 13 イベントのサブスクライブ
今回はprocessaction.actioncontrollerをサブスクライブすることで controller の動作の通知を受け取ります。
通知を受けて ActiveSupport::Notifications から渡される情報からログを作成し、公式が出しているfluent-logger-rubyを利用して、fluentd へログを送りました。
この方式をとることで、lograge 相当のログの情報を残しつつ、ログ内容の改変や追加などを行うことができました。
Redash にてアクセスログの解析
Redash を用いて Athena からアクセスログの解析を行いました。
Redash はデータ視覚化を行うことのできるサービスで Athena や BigQuery などなどのデータにアクセスし、グラフや表などの形で非エンジニアの方も閲覧しやすい形にまとめることができます。
- 指定したユーザー・日付のアクセスログを時間順に表示する
- 指定した日付の API(path)ごとの呼び出し回数の統計を表示する。グラフで可視化してみる
- 指定した日付の例外が発生しているアクセスログを時間順に最大 1000 件まで表示
- 上記例外が発生した 1 日の API ごとの統計をとる
などのクエリを追加しました。
苦労した点
fluentd 分からん
頑張りました。
割とシンプルなので助かりました
Rails 分からん
Rails を扱った軽い経験は一応ありましたが、最終的に使用した Active Support::Notifications は存在すらしらず、かなり試行錯誤していました。
ちなみに具体的に他に検討した案&没理由は以下の通りです。
・lograge の custom_options 内で無理やり fluentd にログを飛ばす
→ トリッキーなので却下
・ApplicationController の before_action にログの出力を行う関数を挟む
→ リクエストに対するレスポンス内容などのリクエスト内容以外の情報が取得できず却下。 また、レスポンス内容は別で出力！とかにしても複数コンテナが書き込むログの中でどのリクエストとレスポンスが紐づくかわからなくなるのでそれも却下
終わりに
今回はシルバーウィークを挟んで 3 週間という期間でしたが、ログ周辺のシステムを広く触る経験ができたのはとても良い経験でした。ログ配信周りは今まで開発の経験も知見もなく、あまり個人開発では手が回らないような部分なのでとても貴重な経験になったと感じています。
3 週間お世話になりました！！！
