This post is inspired by Monitoring Slow SQL Queries via Slack. After reading that, I thought, how we can implement this in Rails. Then after a thorough search, I found that ActiveSupport:: Notifications could help us in achieving this. ActiveSupport:: Notifications provides an instrumentation API to track not only SQL queries but also view rendering information. Prior monitoring SQL queries, one should subscribe eventsql.active_record along with callback as shown below.

callback = lambda {|*args| ... }
ActiveSupport::Notifications
  .subscribed(callback,"sql.active_record") do
  # your code is here
end

For every SQL that fires by an active record, callback will get executed.

callback = lambda do |_, start_time, end_time, *args|
  puts args.last[:sql]
  puts "#{(end_time - start_time) * 1000} ms"
end
ActiveSupport::Notifications.subscribed(callback, "sql.active_record") do
   Farmer.accessible_by(current_ability).first(10)
end

When you run above code you would following output:

Log SQL queries on the console

Now let’s notify these slow queries on to slack. First, you have to register slack webhook URL. After that please follow steps below:

# Gemfile
gem 'slack-notifier'

in your codebase, please add following code:

if duration > 2.0
  url = <slack webhook URL>
  notifier = Slack::Notifier.new url, 
             channel: "#ror", 
             username: "SQL-bot"
  attachment = {
     fallback: '',
     text: "#{sql} took #{duration}",
     color: "warning"
  }

  notifier.post text: "Slow SQL Queries", attachments: [attachment]
end

Final code will appear as below once you merged instrumentation and notifications:

callback = lambda do |_, start_time, end_time, *args|
  sql = args.last[:sql]
  duration = (end_time - start_time) * 1000
  if duration > 2.0
    url = <slack webhook URL>
    notifier = Slack::Notifier.new url, channel: "#ror", 
                                        username: "SQL-bot"
  attachment = {
      fallback: '',
      text: "#{sql} took #{duration}",
      color: "warning"
  }

  notifier.post text: "Slow SQL Queries", attachments: [attachment]
end
ActiveSupport::Notifications.subscribed(callback, "sql.active_record") do
     Farmer.accessible_by(current_ability).first(10)
   end
end

And on your slack

Notification in slack

This is a basic version of instrumenting your code base. For detailed metrics, it’s better to use some tools like new-relic or skylight.

Thanks for reading. Happy query logging!!!.

Effective querying using SQL over Rails Effective querying using SQL over Rails

Most of the rails developers write queries on daily basis. Some of the other day by mistake we follow rails way instead of SQL way to do tasks like sorting etc. But you might ask what’s the problem regarding which approach I take as long as I am able to get correct results. Yes, you may get correct results but you will end up with performance problems in future. Following a set of scenarios I am observed that SQL querying out powered rails:

Apply sorting on a combination of different tables

I have three tables namely deposits, purchases and withdraws. Now, I want to display latest three records from a combination of three tables.

  • Let’s check rails way

Benchmark.ms do 
  (Deposit.all + Purchase.all + Withdraw.all).sort do |x, y|       x.updated_at <=> y.updated_at
  end
end
Deposit Load (0.6ms) SELECT "deposits".* FROM "deposits"
Purchase Load (0.4ms) SELECT "purchases".* FROM "purchases" 
Withdraw Load (0.7ms) SELECT "withdraws".* FROM "withdraws"
=> 121.91500002518296
  • Let’s check SQL way

SELECT 'deposit', authorization_code, amount, status, updated_at FROM DEPOSITS 
ORDER BY updated_at 
DESC LIMIT 3)
UNION
(SELECT 'purchase', ref, amount, status, updated_at FROM PURCHASES ORDER BY updated_at 
DESC LIMIT 3) 
UNION
(SELECT 'withdraw', ref, amount, status, updated_at FROM WITHDRAWS ORDER BY updated_at 
DESC LIMIT 3)
ORDER BY updated_at DESC LIMIT 3
=> SQL (2.0ms)

Apply sorting on different types of data

Let’s say a table stores gifs, videos of different duration. Now I want sort videos, gifs in ascending order of content duration separately.

  • Let’s check rails way

Benchmark.ms do 
   videos = SpotBooking.where(content_type:'video')
                       .order('content_duration DESC')
gifs = SpotBooking.where(content_type:'gif')
                     .order('content_duration DESC')
videos + gifs 
end
 
SpotBooking Load (0.4ms) SELECT "spot_bookings".* FROM "spot_bookings" WHERE "spot_bookings"."content_type" = $1 ORDER BY content_duration DESC [["content_type", 3]]
SpotBooking Load (0.4ms) SELECT "spot_bookings".* FROM "spot_bookings" WHERE "spot_bookings"."content_type" = $1 ORDER BY content_duration DESC [["content_type", 2]]
=> 12.477000011131167
  • Let’s check SQL way

SELECT id, content_duration, row_number() 
OVER (PARTITION BY content_type ORDER BY content_duration DESC) 
FROM spot_bookings
=> SQL (0.8ms)

Formatting the data while querying

  • Let’s check rails way

Benchmark.ms do 
  h = {} 
  pricings = SpotPricing.order('starts_at ASC') 
  pricings.each do |b|    
    h[b.starts_at.strftime("%H %M %P")] = b.price.to_f 
  end 
end
SpotPricing Load (0.5ms) SELECT "spot_pricings".* FROM "spot_pricings" ORDER BY starts_at ASC
=> 35.459000151604414
# output
{"02:19 AM"=>"1.00", "03:19 AM"=>"2.00", "04:19 AM"=>"3.00",  
 "05:19 AM"=>"4.00", "06:19 AM"=>"5.00", "07:19 AM"=>"6.00", 
 "08:19 AM"=>"7.00", "09:19 AM"=>"8.00", "10:19 AM"=>"9.00",
 "11:19 AM"=>"10.00", "12:19 PM"=>"11.00", "13:19 PM"=>"12.00",  "14:19 PM"=>"13.00", "15:19 PM"=>"14.00", "16:19 PM"=>"15.00",  "17:19 PM"=>"16.00", "18:19 PM"=>"17.00", "19:19 PM"=>"18.00", "20:19 PM"=>"19.00", "21:19 PM"=>"20.00", "23:19 PM"=>"22.00", "00:19 AM"=>"23.00"}
  • Let’s check SQL way

SpotPricing.order('starts_at ASC').pluck("to_char(starts_at, 'HH24:MI AM')", "to_char(price, 'FM999999999.00')")
SELECT to_char(starts_at, 'HH24:MI AM'), to_char(price, 'FM999999999.00') FROM "spot_pricings" ORDER BY ASC
=> SQL (0.5ms)
# Output
{"02:19 AM"=>"1.00", "03:19 AM"=>"2.00", "04:19 AM"=>"3.00", 
 "05:19 AM"=>"4.00", "06:19 AM"=>"5.00", "07:19 AM"=>"6.00", 
 "08:19 AM"=>"7.00", "09:19 AM"=>"8.00", "10:19 AM"=>"9.00", 
 "11:19 AM"=>"10.00", "12:19 PM"=>"11.00", "13:19 PM"=>"12.00",    "14:19 PM"=>"13.00", "15:19 PM"=>"14.00", "16:19 PM"=>"15.00", "17:19 PM"=>"16.00", "18:19 PM"=>"17.00", "19:19 PM"=>"18.00", "20:19 PM"=>"19.00", "21:19 PM"=>"20.00", "23:19 PM"=>"22.00", "00:19 AM"=>"23.00"}

In all above scenarios, SQL plays best compared to conventional rails way. Sometimes I would feel it’s not a big deal if you not follow design patterns as long as your ability to provide the best outcome.

Any suggestions and feedback would be welcome!!!

Happy querying!!!


Originally published at railslearning.wordpress.com on July 31, 2017.

Want to explore all the ways you can start, run & grow your business?