Thursday, March 26, 2015

Estimating MySQL rollback time in InnoDB

0 comments
Estimating (computing) rollback time in MySQL can be a bit of a pain (art), but it can be done. MySQL provides data about rollbacks in InnoDB through SHOW ENGINE INNODB STATUS output. Here's a sample:

---TRANSACTION 2920ACF08, ACTIVE 12568 sec rollback
ROLLING BACK 2426027 lock struct(s), heap size 216037816, 52624206 row lock(s), undo log entries 3226386
MySQL thread id 5669944, OS thread handle 0x2b126bd21940, query id 2028903424 10.2.3.4 user41
# Query_time: 8736.352709  Lock_time: 0.000151 Rows_sent: 0  Rows_examined: 52624206
SET timestamp=1427378149; 
(query being rolled back)


For estimating rollback time, the important bits here are:
ROLLING BACK 2426027 lock struct(s), heap size 216037816, 52624206 row lock(s), undo log entries 3226386
The "undo log entries" value is the number of undo logs remaining to be rolled back. This value decreases over time. To get to the time remaining, we need at least two samples of this ROLLING BACK line along with timestamps of when those were taken. Put those together and you'll get the rollback rate. Here's rollback rate per second:
rbr = (staring log entries - ending log entries) / (end time in seconds - start time in seconds)
My experience has been that as undo log entries approaches zero, the rollback rate tends to increase. Having said that, if you have your $HOME/.my.cnf set up with your credentials in it, you can use something like this from a Unix (/bin/sh) shell prompt to see a likely up-to-date prediction of when rollback will complete:

$ rbr=161 # Rollback rate per second 
$ while true ; do clear ; x=“`mysql -h HOSTNAME -e 'show engine innodb status \G' | grep ROLLING\ BACK`" ; echo "$x" ; echo -n "Minutes to go: " ; expr `echo "$x" | cut -d, -f4- | cut -d' ' -f5-` / $rbr / 60 ; sleep 5 ; done

It's technically possible to dynamically adjust the value of $rbr, but I've found that it tends to lead to more frustration.