Ridiculously slow SQL queries on Heroku

Question

I'm running a Rails 3 app on Heroku, and using NewRelic to monitor performance. Every few hours, I'm seeing reports of VERY slow queries, which make no sense to me.

For example, I have an Events table that has year, month, and day columns (thinking about this now, it's probably not the most efficient design, but regardless I don't think it should slow down the queries so badly). This table is indexed on 4 columns, (user_id, year, month, day - ordered by day).

NewRelic is showing that the database takes 3.2 seconds to run the following query. I have no idea why, because the entire table only has about 6k rows, and my entire app is only serving an average of 5.67 requests per minute.

Is there something I'm missing here? Perhaps it's because I'm only on a single web dyno, and that dyno is going to sleep? If that's the case, why would NewRelic report it as a slow SQL query?

SELECT `events`.* FROM `events` WHERE `events`.`user_id` = 5308 AND `events`.`year` = 2014 AND `events`.`month` = 1 ORDER BY day ASC

Here is the SQL EXPLAIN on the query:

 Query plan Sort (cost=20.50..20.50 rows=11 width=89)   
Query plan   Sort Key: day
Query plan   -> Bitmap Heap Scan on events (cost=2.08..20.46 rows=11 width=89)
Query plan   Recheck Cond: ((user_id = 5308) AND (year = 2014) AND (month = 1))
Query plan   -> Bitmap Index Scan on index_events_on_user_id_and_year_and_month_and_day (cost=0.00..2.08 rows=11 width=0)
Query plan   Index Cond: ((user_id = 5308) AND (year = 2014) AND (month = 1))

Answer 1

What New Relic is reporting is not just the time required to run the query on the database server. What's reported is a wider measurement. It includes time spent to prepare the query via ActiveRecord, send the query over the wire to the database server, execute the query, receive the response over the wire from the database server and parse the response back into a set of Ruby objects in ActiveRecord.

Usually, the time taken to actually execute the query on the database server will dominate this measurement but not always. There are a huge variety of different factors that contribute to the time measured and a delay at any level of the stack can contribute to the reported time.