Active Support Instrumentation

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

  Rails.logger.info "#{event} Received!"
end

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |name, started, finished, unique_id, payload|
  # your own custom stuff
  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

ActiveSupport::Notifications.monotonic_subscribe "process_action.action_controller" do |name, started, finished, unique_id, payload|
  # your own custom stuff
  duration = finished - started # 1560979.429234 - 1560978.425334
  Rails.logger.info "#{name} Received! (duration: #{duration})" # process_action.action_controller Received! (duration: 1.0039)
end

ActiveSupport::Notifications.subscribe(/action_controller/) do |event|
  # inspect all ActionController events
end

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

{
  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
}

{
  status: 302,
  location: "https://127.0.0.1:3000/posts/new",
  request: <ActionDispatch::Request:0x00007ff1cb9bd7b8>
}

{
  filter: ":halting_filter"
}

{
  filename: "subscribers.csv",
  type: "text/csv",
  disposition: "attachment"
}

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

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

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

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

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

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

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

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

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

{
  record_count: 1,
  class_name: "User"
}

ActiveRecord::Base.transaction do
  # We are inside the block, but no event has been triggered yet.

  # The following line makes Active Record start the transaction.
  User.count # Event fired here.
end

ActiveRecord::Base.transaction do |t1|
  User.count # Fires an event for t1.
  ActiveRecord::Base.transaction do |t2|
    # The next line fires no event for t2, because the only
    # real database transaction in this example is t1.
    User.first.touch
  end
end

ActiveRecord::Base.transaction do |t1|
  User.count # Fires an event for t1.
  ActiveRecord::Base.transaction(requires_new: true) do |t2|
    User.first.touch # Fires an event for t2.
  end
end

{
  mailer: "Notification",
  message_id: "[email protected]",
  subject: "Rails Guides",
  to: ["[email protected]", "[email protected]"],
  from: ["[email protected]"],
  date: Sat, 10 Mar 2012 14:18:09 +0100,
  mail: "...", # omitted for brevity
  perform_deliveries: true
}

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

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

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

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

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

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

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

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

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

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

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

{
  serializer: :json_allow_marshal,
  fallback: :marshal,
  serialized: "\x04\b{\x06I\"\nHello\x06:\x06ETI\"\nWorld\x06;\x00T",
  deserialized: { "Hello" => "World" },
}

{
  mailbox: #<RepliesMailbox:0x00007f9f7a8388>,
  inbound_email: {
    id: 1,
    message_id: "[email protected]",
    status: "processing"
  }
}

ActiveSupport::Notifications.instrument "my.custom.event", this: :data do
  # do your custom stuff here
end

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

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