ruby 43 lines · 7 steps

Logging slow SQL queries in Rails

A module that subscribes to ActiveRecord's SQL notifications and warns whenever a query crosses a duration threshold.

Explained by highlit
Rails Intermediate instrumentation logging pub-sub observability performance
1module SlowQueryLogger
2 SLOW_QUERY_THRESHOLD_MS = 200.0
3 IGNORED_PAYLOAD_NAMES = %w[SCHEMA TRANSACTION].freeze
4 
5 module_function
6 
7 def subscribe!
8 ActiveSupport::Notifications.subscribe("sql.active_record") do |*args|
9 event = ActiveSupport::Notifications::Event.new(*args)
10 log_if_slow(event)
11 end
12 end
13 
14 def log_if_slow(event)
15 return if event.duration < SLOW_QUERY_THRESHOLD_MS
16 return if IGNORED_PAYLOAD_NAMES.include?(event.payload[:name])
17 return if event.payload[:cached]
18 
19 Rails.logger.warn do
20 binds = format_binds(event.payload[:type_casted_binds])
21 <<~LOG.squish
22 [SlowQuery] #{event.duration.round(1)}ms
23 name=#{event.payload[:name].inspect}
24 sql=#{event.payload[:sql].squish.truncate(500)}
25 binds=#{binds}
26 source=#{query_source}
27 LOG
28 end
29 end
30 
31 def format_binds(binds)
32 return "[]" if binds.blank?
33 
34 casted = binds.respond_to?(:call) ? binds.call : binds
35 casted.map { |value| value.inspect.truncate(50) }.join(", ")
36 end
37 
38 def query_source
39 Rails.backtrace_cleaner.clean(caller).find do |line|
40 line.include?("/app/")
41 end || "unknown"
42 end
43end
01 / 01
STEP 01

Walkthrough

Space play ←→ step click any line
Three takeaways
  1. 1ActiveSupport::Notifications lets you observe SQL without patching ActiveRecord internals.
  2. 2Guard clauses filter out noise like cached hits and schema queries before you pay logging costs.
  3. 3Passing a block to Rails.logger.warn defers expensive string building until the level is actually enabled.

Related explainers

ruby 
require "net/http"
require "json"
require "uri"
require "base64"

Paginating an HTTP API with a Ruby enumerator

pagination http enumerator
Intermediate 7 steps
ruby 
class DateRangeMerger
  def initialize(ranges)
    @ranges = ranges
  end

Merging overlapping date ranges in Ruby

sorting interval-merging enumerable
Intermediate 5 steps
python 
import logging
import uuid
from contextvars import ContextVar
 

Request ID tracing in FastAPI middleware

middleware context-variables request-tracing
Intermediate 7 steps
ruby 
require "phonelib"
 
class PhoneNumber
  class InvalidNumber < StandardError; end

Wrapping phone parsing in a Ruby value object

value-object memoization validation
Intermediate 7 steps
javascript 
const express = require('express');
const EventEmitter = require('events');
 
const router = express.Router();

Server-Sent Events with Express

server-sent-events streaming event-emitter
Advanced 8 steps
python 
import json
import time
import queue
 

Server-Sent Events streaming in Flask

server-sent-events streaming pub-sub
Advanced 9 steps

Share this explainer

Here's the card — post it anywhere.

Logging slow SQL queries in Rails — share card
Made with highlit — turn any snippet into a walkthrough like this in about a minute.
Explain your code