Active Support の Instrumentation 機能

Active SupportはRailsのコア機能の1つであり、Ruby言語の拡張、ユーティリティなどを提供するものです。Active Supportに含まれているInstrumentation APIは、Rubyコードで発生する特定の動作の計測に利用できます。Railsアプリケーション内部やフレームワーク自身の計測はもちろん、必要であればRails以外のRubyスクリプトなども測定できます。

本ガイドでは、RailsなどのRubyコード内のイベント計測に使われる、Active SupportのInstrumentation APIについて解説します。

このガイドの内容:

Instrumentationでできること
Railsフレームワーク内のInstrumentationフック
フックにサブスクライバを追加する
独自のInstrumentationを実装する

1 Instrumentationについて

Active Supportが提供するInstrumentation APIを使ってフックを開発すると、他の開発者がそこにフックできるようになります。Railsフレームワーク内部にはさまざまなフックが用意されています。このAPIをアプリケーションで実装すると、アプリケーション（またはRubyコード片）内部でイベントが発生したときに通知を受け取れるよう他の開発者が設定できます。

たとえばActive Recordには、データベースへのSQLクエリが発行されるたびに呼び出されるフックが用意されています。このフックをサブスクライブ（購読）すると、特定のアクションでのクエリ実行数を追跡できます。他に、コントローラのアクション実行中に呼び出されるフックもあります。このフックは、たとえば特定のアクション実行に要した時間のトラッキングに利用できます。

アプリケーション内に独自のイベントを作成し、後で自分でサブスクライブして測定することも可能です。

2 イベントのサブスクライブ

イベントは簡単にサブスクライブできます。ActiveSupport::Notifications.subscribeをブロック付きで記述すれば、すべての通知をリッスンできます。

ブロックには以下の引数を渡せます。

イベント名
イベントの開始時刻
イベントの終了時刻
イベントを発火させたinstrumenterのユニークID
イベントのペイロード

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |name, started, finished, unique_id, data|
  # 自分のコードをここに書く
  Rails.logger.INFO:"#{name} Received! (started: #{started}, finished: #{finished})" # process_action.action_controller Received (started: 2019-05-05 13:43:57 -0800, finished: 2019-05-05 13:43:58 -0800)
end

経過時間を正確に算出するうえでstartedとfinishedの精度が気になる場合は、ActiveSupport::Notifications.monotonic_subscribeをお使いください。ここに渡すブロックで使える引数は上述と同じですが、startedとfinishedの値に通常のクロック時刻（wall-clock time）ではなく単調増加する精密な時刻が使われるようになります。

ActiveSupport::Notifications.monotonic_subscribe "process_action.action_controller" do |name, started, finished, unique_id, data|
  # 自分のコードをここに書く
  Rails.logger.INFO:"#{name} Received! (started: #{started}, finished: #{finished})" # process_action.action_controller Received (started: 1560978.425334, finished: 1560979.429234)
end

ブロックの引数を毎回定義しなくても済むよう、次のようなブロック付きのActiveSupport::Notifications::Eventを簡単に定義できます。

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |*args|
  event = ActiveSupport::Notifications::Event.new *args

  event.name      # => "process_action.action_controller"
  event.duration  # => 10 (in milliseconds)
  event.payload   # => {:extra=>information}

  Rails.logger.INFO:"#{event} Received!"
end

また、以下のように引数を1個だけ受け取るブロックを渡すと、イベントオブジェクトを受け取れます。

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |event|
  event.name      # => "process_action.action_controller"
  event.duration  # => 10 (in milliseconds)
  event.payload   # => {:extra=>information}

  Rails.logger.INFO:"#{event} Received!"
end

正規表現に一致するイベントだけをサブスクライブすることも可能です。これはさまざまなイベントを一括でサブスクライブしたい場合に便利です。以下は、ActionControllerのイベントをすべて登録する場合の例です。

ActiveSupport::Notifications.subscribe /action_controller/ do |*args|
  # ActionControllerの全イベントをチェック
end

3 Railsフレームワーク用フック

Ruby on Railsでは、フレームワーク内の主なイベント向けのフックが多数提供されています。イベントとペイロードについて詳しくは以下をご覧ください。

3.1 Action Controller

3.1.1 `start_processing.action_controller`

キー	値
`:controller`	コントローラ名
`:action`	アクション
`:params`	リクエストパラメータのハッシュ（フィルタされたパラメータは含まない）
`:headers`	リクエストヘッダー
`:format`	html/js/json/xml など
`:method`	HTTP リクエストメソッド（verb）
`:path`	リクエストパス

{
  controller: "PostsController",
  action: "new",
  params: { "action" => "new", "controller" => "posts" },
  headers: #<ActionDispatch::Http::Headers:0x0055a67a519b88>,
  format: :html,
  method: "GET",
  path: "/posts/new"
}

3.1.2 `process_action.action_controller`

キー	値
`:controller`	コントローラ名
`:action`	アクション
`:params`	リクエストパラメータのハッシュ（フィルタされたパラメータは含まない）
`:headers`	リクエストヘッダー
`:format`	html/js/json/xml など
`:method`	HTTP リクエストメソッド（verb）
`:path`	リクエストパス
`:request`	`ActionDispatch::Request`オブジェクト
`:response`	`ActionDispatch::Response`オブジェクト
`:status`	HTTPステータスコード
`:view_runtime`	ビューでかかった合計時間（ms）
`:db_runtime`	データベースへのクエリ実行にかかった時間（ms）

{
  controller: "PostsController",
  action: "index",
  params: {"action" => "index", "controller" => "posts"},
  headers: #<ActionDispatch::Http::Headers:0x0055a67a519b88>,
  format: :html,
  method: "GET",
  path: "/posts",
  request: #<ActionDispatch::Request:0x00007ff1cb9bd7b8>,
  response: #<ActionDispatch::Response:0x00007f8521841ec8>,
  status: 200,
  view_runtime: 46.848,
  db_runtime: 0.157
}

3.1.3 `send_file.action_controller`

キー	値
`:path`	ファイルへの完全なパス

呼び出し側でキーが追加される可能性があります。

3.1.4 `send_data.action_controller`

ActionControllerはペイロードに特定の情報を追加しません。オプションは、すべてペイロード経由で渡されます。

3.1.5 `redirect_to.action_controller`

キー	値
`:status`	HTTP レスポンスコード
`:location`	リダイレクト先URL
`:request`	`ActionDispatch::Request`オブジェクト

{
  status: 302,
  location: "http://localhost:3000/posts/new"
}

3.1.6 `halted_callback.action_controller`

キー	値
`:filter`	アクションを停止させたフィルタ

{
  filter: ":halting_filter"
}

3.1.7 `unpermitted_parameters.action_controller`

キー	値
`:keys`	許可されていないキー
`:context`	以下のキーを持つハッシュ: `:controller`、`:action`、`:params`、`:request`

3.2 Action Controller — キャッシング

3.2.1 `write_fragment.action_controller`

キー	値
`:key`	完全なキー

{
  key: 'posts/1-dashboard-view'
}

3.2.2 `read_fragment.action_controller`

キー	値
`:key`	完全なキー

{
  key: 'posts/1-dashboard-view'
}

3.2.3 `expire_fragment.action_controller`

キー	値
`:key`	完全なキー

{
  key: 'posts/1-dashboard-view'
}

3.2.4 `exist_fragment?.action_controller`

キー	値
`:key`	完全なキー

{
  key: 'posts/1-dashboard-view'
}

3.3 Action Dispatch

3.3.1 `process_middleware.action_dispatch`

キー	値
`:middleware`	ミドルウェア名

3.4 Action View

3.4.1 `render_template.action_view`

キー	値
`:identifier`	テンプレートへの完全なパス
`:layout`	該当のレイアウト

{
  identifier: "/Users/adam/projects/notifications/app/views/posts/index.html.erb",
  layout: "layouts/application"
}

3.4.2 `render_partial.action_view`

キー	値
`:identifier`	テンプレートへの完全なパス

{
  identifier: "/Users/adam/projects/notifications/app/views/posts/_form.html.erb"
}

3.4.3 `render_collection.action_view`

キー	値
`:identifier`	テンプレートへのフルパス
`:count`	コレクションのサイズ
`:cache_hits`	キャッシュからフェッチしたパーシャルの個数

:cache_hitsは、cached: trueをオンにしてレンダリングしたときだけ含まれます。

{
  identifier: "/Users/adam/projects/notifications/app/views/posts/_post.html.erb",
  count: 3,
  cache_hits: 0
}

3.4.4 `render_layout.action_view`

キー	値
`:identifier`	テンプレートへのフルパス

{
  identifier: "/Users/adam/projects/notifications/app/views/layouts/application.html.erb"
}

3.5 Active Record

3.5.1 `sql.active_record`

キー	値
`:sql`	SQL文
`:name`	操作の名前
`:connection`	コネクションオブジェクト
`:binds`	バインドするパラメータ
`:type_casted_binds`	型キャストされたバインドパラメータ
`:statement_name`	SQL文の名前
`:cached`	キャッシュされたクエリが使われると`true`が追加される

アダプタが独自のデータを追加する可能性もあります。

{
  sql: "SELECT \"posts\".* FROM \"posts\" ",
  name: "Post Load",
  connection: #<ActiveRecord::ConnectionAdapters::SQLite3Adapter:0x00007f9f7a838850>,
  binds: [#<ActiveModel::Attribute::WithCastValue:0x00007fe19d15dc00>],
  type_casted_binds: [11],
  statement_name: nil
}

3.5.2 `instantiation.active_record`

キー	値
`:record_count`	レコードのインスタンス数
`:class_name`	レコードのクラス

{
  record_count: 1,
  class_name: "User"
}

3.6 Action Mailer

3.6.1 `deliver.action_mailer`

キー	値
`:mailer`	メーラークラス名
`:message_id`	Mail gemが生成したメッセージID
`:subject`	メールの件名
`:to`	メールの宛先（複数可）
`:from`	メールの差出人
`:bcc`	メールのBCCアドレス（複数可）
`:cc`	メールのCCアドレス（複数可）
`:date`	メールの日付
`:mail`	メールのエンコード形式
`:perform_deliveries`	このメッセージが配信されたかどうか

{
  mailer: "Notification",
  message_id: "4f5b5491f1774_181b23fc3d4434d38138e5@mba.local.mail",
  subject: "Rails Guides",
  to: ["users@rails.com", "dhh@rails.com"],
  from: ["me@rails.com"],
  date: Sat, 10 Mar 2012 14:18:09 +0100,
  mail: "...", # （省略）
  perform_deliveries: true
}

3.6.2 `process.action_mailer`

キー	値
`:mailer`	メーラーのクラス名
`:action`	アクション
`:args`	引数

{
  mailer: "Notification",
  action: "welcome_email",
  args: []
}

3.7 Active Support -- キャッシング

3.7.1 `cache_read.active_support`

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名
`:hit`	ヒットしたかどうか
`:super_operation`	読み出しに`fetch`が使われる場合に`:fetch`を追加

3.7.2 `cache_read_multi.active_support`

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名
`:hit`	ヒットしたかどうか
`:super_operation`	読み出しに`fetch_multi`が使われる場合に`:fetch_multi`を追加

3.7.3 `cache_generate.active_support`

このイベントは、fetchをブロック付きで呼び出した場合にのみ使われます。

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名

fetchに渡されたオプションは、ストアへの書き込み時にペイロードとマージされます。

{
  key: "name-of-complicated-computation",
  store: "ActiveSupport::Cache::MemCacheStore"
}

3.7.4 `cache_fetch_hit.active_support`

このイベントは、fetchをブロック付きで呼び出した場合にのみ使われます。

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名

fetchに渡されたオプションは、ペイロードとマージされます。

{
  key: "name-of-complicated-computation",
  store: "ActiveSupport::Cache::MemCacheStore"
}

3.7.5 `cache_write.active_support`

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名

キャッシュストアが独自のキーを追加することがあります。

{
  key: "name-of-complicated-computation",
  store: "ActiveSupport::Cache::MemCacheStore"
}

3.7.6 `cache_write_multi.active_support`

キー	値
`:key`	ストアに書き込まれるキーと値
`:store`	ストアクラス名

3.7.7 `cache_increment.active_support`

このイベントが発火するのは、MemCacheStoreまたはRedisCacheStoreを使っている場合のみです。

キー	値
`:key`	ストアに書き込まれるキーと値
`:store`	ストアクラス名
`:amount`	インクリメントの総量

{
  key: "bottles-of-beer",
  store: "ActiveSupport::Cache::RedisCacheStore",
  amount: 99
}

3.7.8 `cache_decrement.active_support`

このイベントが発火するのは、MemCacheStoreまたはRedisCacheStoreを使っている場合のみです。

キー	値
`:key`	ストアに書き込まれるキーと値
`:store`	ストアクラス名
`:amount`	デクリメントの総量

{
  key: "bottles-of-beer",
  store: "ActiveSupport::Cache::RedisCacheStore",
  amount: 1
}

3.7.9 `cache_delete.active_support`

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名

{
  key: "name-of-complicated-computation",
  store: "ActiveSupport::Cache::MemCacheStore"
}

3.7.10 `cache_delete_multi.active_support`

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名

3.7.11 `cache_delete_matched.active_support`

このイベントが発火するのは、RedisCacheStore、FileStore、またはMemoryStoreを使っている場合のみです。

キー	値
`:key`	使われるキーパターン
`:store`	ストアクラス名

{
  key: "posts/*",
  store: "ActiveSupport::Cache::RedisCacheStore"
}

3.7.12 `cache_cleanup.active_support`

このイベントが発火するのは、MemoryStoreを使っている場合のみです。

キー	値
`:store`	ストアクラス名
`:size`	クリーンアップ前のキャッシュにあるエントリ数

{
  store: "ActiveSupport::Cache::MemoryStore",
  size: 9001
}

3.7.13 `cache_prune.active_support`

このイベントが発火するのは、MemoryStoreを使っている場合のみです。

キー	値
`:store`	ストアクラス名
`:key`	キャッシュのターゲットサイズ（バイト単位）
`:from`	prune前のキャッシュサイズ（バイト単位）

{
  store: "ActiveSupport::Cache::MemoryStore",
  key: 5000,
  from: 9001
}

3.7.14 `cache_exist?.active_support`

キー	値
`:key`	ストアで使われるキー
`:store`	ストアクラス名

{
  key: "name-of-complicated-computation",
  store: "ActiveSupport::Cache::MemCacheStore"
}

3.8 Active Job

3.8.1 `enqueue_at.active_job`

キー	値
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:job`	Jobオブジェクト

3.8.2 `enqueue.active_job`

キー	値
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:job`	Jobオブジェクト

3.8.3 `enqueue_retry.active_job`

キー	値
`:job`	Jobオブジェクト
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:error`	リトライが原因で発生したエラー
`:wait`	リトライの遅延

3.8.4 `perform_start.active_job`

キー	値
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:job`	Jobオブジェクト

3.8.5 `perform.active_job`

キー	値
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:job`	Jobオブジェクト

3.8.6 `retry_stopped.active_job`

キー	値
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:job`	Jobオブジェクト
`:error`	リトライが原因で発生したエラー

3.8.7 `discard.active_job`

キー	値
`:adapter`	ジョブを処理するQueueAdapterオブジェクト
`:job`	Jobオブジェクト
`:error`	リトライが原因で発生したエラー

3.9 Action Cable

3.9.1 `perform_action.action_cable`

キー	値
`:channel_class`	チャネルのクラス名
`:action`	アクション
`:data`	日付（ハッシュ）

3.9.2 `transmit.action_cable`

キー	値
`:channel_class`	チャネルのクラス名
`:action`	アクション
`:via`	経由先

3.9.3 `transmit_subscription_confirmation.action_cable`

キー	値
`:channel_class`	チャネルのクラス名

3.9.4 `transmit_subscription_rejection.action_cable`

キー	値
`:channel_class`	チャネルのクラス名

3.9.5 `broadcast.action_cable`

キー	値
`:broadcasting`	名前付きブロードキャスト
`:message`	メッセージ（ハッシュ）
`:coder`	コーダー

3.10 Active Storage

3.10.1 `preview.active_storage`

キー	値
`:key`	セキュアトークン

3.10.2 `transform.active_storage`

3.10.3 `analyze.active_storage`

キー	値
`:analyzer`	アナライザ名（ffprobeなど）

3.11 Active Storage — ストレージサービス

3.11.1 `service_upload.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名
`:checksum`	完全性を担保するチェックサム

3.11.2 `service_streaming_download.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名

3.11.3 `service_download_chunk.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名
`:range`	読み取りを試行するバイト範囲

3.11.4 `service_download.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名

3.11.5 `service_download.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名

3.11.6 `service_delete_prefixed.active_storage`

キー	値
`:prefix`	キーのプレフィックス
`:service`	サービス名

3.11.7 `service_exist.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名
`:exist`	ファイルまたはblobが存在するかどうか

3.11.8 `service_url.active_storage`

キー	値
`:key`	セキュアトークン
`:service`	サービス名
`:url`	生成されたURL

3.11.9 `service_update_metadata.active_storage`

このイベントが発火するのは、Google Cloud Storageサービスを使っている場合のみです。

キー	値
`:key`	セキュアトークン
`:service`	サービス名
`:content_type`	HTTP Content-Typeフィールド
`:disposition`	HTTP Content-Dispositionフィールド

3.12 Railties

3.12.1 `load_config_initializer.railties`

キー	値
`:initializer`	`config/initializers`で読み込まれたイニシャライザへのパス

3.13 Rails

3.13.1 `deprecation.rails`

キー	値
`:message`	非推奨機能の警告メッセージ
`:callstack`	非推奨警告の発生元

4 例外

instrumentationの途中で例外が発生すると、ペイロードにその情報が含まれます。

キー	値
`:exception`	2個の要素（例外クラス名とメッセージ）を持つ配列
`:exception_object`	例外オブジェクト

5 カスタムイベントの作成

独自のイベントも手軽に追加できます。面倒な作業はActive Supportが代行するので、ActiveSupport::Notifications.instrumentにname、payload、およびブロックを指定して呼び出すだけでイベント追加が完了します。通知は、ブロックから制御が戻った後で送信されます。Active Supportでは、開始時刻、終了時刻、およびinstrumenterのユニークIDが生成されます。instrument呼び出しに渡されるすべてのデータがペイロードに含まれます。

以下に例を示します。

ActiveSupport::Notifications.instrument "my.custom.event", this: :data do
  # 自分のコードをここに書く
end

これで、次のようにイベントをリッスンできるようになります。

ActiveSupport::Notifications.subscribe "my.custom.event" do |name, started, finished, unique_id, data|
  puts data.inspect # {:this=>:data}
end

以下のように、instrumentにブロックを渡さずに呼び出すことも可能です。これにより、instrumentationインフラストラクチャを他のメッセージング用途に活用できます。

ActiveSupport::Notifications.instrument "my.custom.event", this: :data

ActiveSupport::Notifications.subscribe "my.custom.event" do |name, started, finished, unique_id, data|
  puts data.inspect # {:this=>:data}
end

独自のイベントを作成するときは、Railsの規約に従ってください。形式は「event.library」を使います。たとえば、アプリケーションがツイートを送信するのであれば、イベント名はtweet.twitterとなります。

🖋 GitHubで編集を提案する / 📕 英語で読む

フィードバックについて

Railsガイドは GitHub の yasslab/railsguides.jp で管理・公開されております。本ガイドを読んで気になる文章や間違ったコードを見かけたら、気軽に Pull Request を出して頂けると嬉しいです。Pull Request の送り方については GitHub の README をご参照ください。

原著における間違いを見つけたら『Rails のドキュメントに貢献する』を参考にしながらぜひ Rails コミュニティに貢献してみてください 🛠💨✨

本ガイドの品質向上に向けて、皆さまのご協力が得られれば嬉しいです。

Railsガイド運営チーム (@RailsGuidesJP)

支援・協賛

Railsガイドは下記の協賛企業から継続的な支援を受けています。支援・協賛にご興味あれば協賛プランからお問い合わせいただけると嬉しいです。

Star

/ 検索を開始	ctrl + p 前の検索項目	↑ 前の検索項目
esc フォーカスを解除	ctrl + n 次の検索項目	↓ 次の検索項目
cmd + f ページ内検索 (ブラウザ標準)	? ヘルプの表示

Keybord Shortcuts

Active Support の Instrumentation 機能

目次