Eavesdropping on ActiveRecord: Instrumentation for Logging and Auditing
Your models shouldn’t know they’re being watched.
Rails has a built-in pub/sub system called ActiveSupport::Notifications that fires events for almost everything ActiveRecord does. You can subscribe to these events from anywhere — a separate class, an initializer, a dedicated auditing module — without adding a single line to your models.
This is decoupling in practice: the thing doing the work doesn’t know about the thing recording it.
The basics
Every SQL query ActiveRecord runs fires a sql.active_record event. You can subscribe to it like this:
# config/initializers/sql_logging.rb
ActiveSupport::Notifications.subscribe("sql.active_record") do |event|
payload = event.payload
Rails.logger.info({
event: "sql.active_record",
sql: payload[:sql],
duration_ms: event.duration.round(2),
name: payload[:name],
timestamp: event.time
}.to_json)
end
That’s it. Every query your app runs now gets logged as structured JSON. Your models didn’t change. Your controllers didn’t change. Nothing changed except a new initializer that listens.
Useful ActiveRecord events
Rails fires more events than you’d expect:
| Event | When it fires |
|---|---|
sql.active_record | Every SQL query |
instantiation.active_record | Objects built from query results |
start_transaction.active_record | Transaction begins |
transaction.active_record | Transaction completes |
You can subscribe to any of them the same way.
Practical example: audit logging
Say you want to log every time a record is created or updated, but you don’t want your models cluttered with after_commit callbacks. Subscribe to the transaction event and inspect what happened:
# config/initializers/audit_subscriber.rb
ActiveSupport::Notifications.subscribe("sql.active_record") do |event|
sql = event.payload[:sql]
next unless sql.match?(/\A\s*(INSERT|UPDATE|DELETE)/i)
Rails.logger.info({
event: "audit.write_operation",
operation: sql[/\A\s*(\w+)/i, 1].upcase,
sql: sql,
duration_ms: event.duration.round(2),
timestamp: event.time
}.to_json)
end
Now every write operation gets logged. No callbacks, no concerns mixed into 30 models, no gem dependencies.
Leveling up with a Subscriber class
If you’re subscribing to multiple events, a dedicated subscriber is cleaner than a pile of blocks:
# app/subscribers/active_record_audit_subscriber.rb
class ActiveRecordAuditSubscriber < ActiveSupport::Subscriber
attach_to :active_record
def sql(event)
return unless event.payload[:sql].match?(/\A\s*(INSERT|UPDATE|DELETE)/i)
AuditLog.later(
operation: event.payload[:sql][/\A\s*(\w+)/i, 1].upcase,
duration_ms: event.duration.round(2),
timestamp: event.time
)
end
def instantiation(event)
return unless event.duration > 100
Rails.logger.warn(
"Slow instantiation: #{event.payload[:record_count]} " \
"#{event.payload[:class_name]} records in #{event.duration.round(2)}ms"
)
end
end
The method names match the event prefix — sql handles sql.active_record, instantiation handles instantiation.active_record. Rails wires it up automatically.
Custom events for business logic
You’re not limited to Rails’ built-in events. Fire your own:
# Anywhere in your app
ActiveSupport::Notifications.instrument("order.completed", order_id: order.id, total: order.total) do
order.fulfill!
end
Then subscribe to it somewhere else entirely:
ActiveSupport::Notifications.subscribe("order.completed") do |event|
SlackNotifier.ping("#sales", "Order #{event.payload[:order_id]} completed: $#{event.payload[:total]}")
end
Your Order model doesn’t know about Slack. The Slack notifier doesn’t know about order internals. They communicate through events. If you rip out the Slack integration next month, you delete one subscriber and nothing else changes.
Why this matters for decoupling
Callbacks and concerns work, but they couple the behavior to the model. Instrumentation inverts that — the observer is responsible for observing, not the subject. Your models stay focused on domain logic. Your logging, auditing, metrics, and notifications live in their own space.
It’s the difference between a model that does twelve things and a model that does one thing while twelve other things watch.