CODEWITHSUNDEEP
mysqlruby-on-railsindexingmysql-workbenchmysql2
channa ly
channa ly

Reputation: 9927

Mysql Index misbehave in rails

I have an rails app hosted with Mysql, there is a reservations table with index set in column rescheduled_reservation_id (nullable).

In my rails app there are two part to query reservation by rescheduled_reservation_id fields as below:

Transit::Reservation.find_by(rescheduled_reservation_id: 25805)

and produce the following log output:

Transit::Reservation Load (60.3ms)  SELECT  `transit_reservations`.* FROM `transit_reservations` WHERE `transit_reservations`.`deleted_at` IS NULL AND `transit_reservations`.`rescheduled_reservation_id` = 25805 LIMIT 1

However the other part of the app:

Transit::Reservation.where(rescheduled_reservation_id: 25805).last

with the log output belows 

Transit::Reservation Load (2.3ms)  SELECT  `transit_reservations`.* FROM `transit_reservations` WHERE `transit_reservations`.`deleted_at` IS NULL AND `transit_reservations`.`rescheduled_reservation_id` = 25805  ORDER BY `transit_reservations`.`id` DESC LIMIT 1

As clearly seen the first query

Transit::Reservation Load (60.3ms)  SELECT  `transit_reservations`.* FROM `transit_reservations` WHERE `transit_reservations`.`deleted_at` IS NULL AND `transit_reservations`.`rescheduled_reservation_id` = 25805 LIMIT 1

took up to 60ms, the index might not have been used properly comparing to 2ms in this

Transit::Reservation Load (2.3ms)  SELECT  `transit_reservations`.* FROM `transit_reservations` WHERE `transit_reservations`.`deleted_at` IS NULL AND `transit_reservations`.`rescheduled_reservation_id` = 25805  ORDER BY `transit_reservations`.`id` DESC LIMIT 1

enter image description here

I also tried to debug further by running explain on both queries, I got back the same result i.e the index rescheduled_reservation_id being used

enter image description here

Is there anyone experiencing with this issue? I am wondering whether rails mysql connection ( I am using mysql2 gem ) might cause Mysql server to not choose the right index

Upvotes: 0

Views: 100

Answers (1)

Rick James
Rick James

Reputation: 142258

It's Rare, but Normal.

The likely answer is that the first occurrence did not find the blocks it needed cached in the buffer_pool. So, it had to fetch them from disk. On a plain ole HDD, a Rule of Thumb is 10ms per disk hit. So, maybe there were 6 blocks that it needed to fetch, leading to 60.3ms.

Another possibility is that other activities were interfering, thereby slowing down this operation.

2.3ms is reasonable for a simple query like that the can be performed entirely with cached blocks in RAM.

Was the server recently restarted? After a restart, there is nothing in cache. Is the table larger than innodb_buffer_pool_size? If so, that would lead to 60ms happening sporadically -- blocks would get bumped out. (Caveat: The buffer_pool should not be made so big that 'swapping' occurs.)

A block is 16KB; it contains some rows of data or rows of index or nodes of a BTree. Depending on the size of the table, even that 'point query' might have needed to look at 6 blocks or more.

If you don't get 2.3ms most of the time, we should dig deeper. (I have hinted at sizes to investigate.)

Upvotes: 2

Related Questions