If you ever had a replication slave that is severely behind, you probably noticed that it’s not catching up with a busy master at a steady pace. Instead, the “Seconds behind master” is going up and down so you can’t really tell whether the replica is catching up or not by looking at just few samples, unless these are spread apart. And even then you can’t tell at a glance when it is going to catch up.

Normally, the “severely behind” thing should not happen, but it does often happen in our consulting practice:

  • sometimes replication would break and then it needs to catch up after it is fixed,
  • other times new replication slave is built from a backup which is normally hours behind,
  • or, it could be that replication slave became too slow to catch up due to missing index

Whatever the case is, single question I am being asked by the customer every time this happens is this: When is the replica going to catch up?”

I used to tell them “I don’t know, it depends..” and indeed it is not an easy question to answer. There are few reasons catching up is so unstable:

  1. If you have restarted the server, or started a new one, caches are cold and there’s a lot of IO happening,
  2. Not all queries are created equal – some would run for seconds, while others can be instant,
  3. Batch jobs: some sites would run nightly tasks like building statistics tables or table checksum – these are usually very intense and cause slave to backup slightly.

I didn’t like my own answer to The question, so I decided to do something about it. And because I love awk, I did that something in awk:

I don’t know if this is ever going to become a part of a Percona Toolkit, however since it’s pretty much a one-liner, I just keep it in my snippets pool for easy copy’n’paste.

Here’s a piece of an output from a server that was almost 27 days behind just yesterday:

Of course, it is still not perfectly accurate and it does not account for any potential changes in queries, workload, warm-up, nor the time it takes to run the mysql cli, but it does give you an idea and direction that replication slave is going. Note, negative values mean replication isn’t catching up, but values themselves are mostly meaningless.

Here’s what the weird acronyms stand for:

  • s_behind – current Seconds_Behind_Master value
  • d_behind – number of days behind based on current s_behind
  • c_sec_s – how many seconds per second were caught up during last interval
  • eta_d – this is ETA based on last interval
  • O_c_sec_s – overall catch-up speed in seconds per second
  • O_eta_d – ETA based on overall catch-up speed (in days)
  • O_eta_h – same like previous but in hours

Let me know if you ever find this useful.

21 Comments
Oldest
Newest Most Voted
Inline Feedbacks
View all comments
Baron Schwartz

Table checksums should not add delay, because pt-table-checksum won’t do anything until replication is caught up.

Michael Wehrle

Can you trust “Seconds_Behind_Master” to be accurate? I have been rebuilding servers lately for a client, and typically by the time we get the new slave built, its between 24-36 hours behind, and something like a dozen binlogs “behind”. What I have found is that the “Seconds_Behind_Master” doesn’t even show non-zero until the slave is on the same binlog as the master. That doesn’t even account for the fact that its often very inaccurate.

Also… 27 days behind? Why not rebuild the slave with a hot backup from the master?

Michael Wehrle

Also, the code is quite nice actually. Succint and useful, given the intent.

Bill Willits

Very nice post. And, super-useful. I’ve had the same need for this tool many times. Thanks for creating.

aftab

Would mk-slave-prefetch help in this situation?

Daniël van Eeden

Thanks for sharing the script.

The line with:
grep Seconds_Behind_Master | awk ‘{print \$2}’

Could be rewritten as:
awk ‘/Seconds_Behind_Master/ { print \$2 }’

It might be possible to use getline and make it more pure awk.
http://www.gnu.org/software/gawk/manual/html_node/Getline_002fVariable_002fPipe.html#Getline_002fVariable_002fPipe

AWK is a great tool. The only downside is that it’s probably not available by default on most Windows and other non-UNIX (like) operating systems.

Rewriting this script to run server side (stored procedure/view/etc) seems favorable, but is not possible:
http://code.openark.org/blog/mysql/reading-results-of-show-statements-on-server-side

Jesse R. Adams

Thanks for sharing this script! It is quite useful!

Frank Van Damme

yes, pretty useful. A lot better than to keep running “show slave status” and making a guess about the time to catch up.

Ross Carver

Why not use statsD or some other data collector in a cronjob and just plot it on a graph? Lots of online tools that will capture/display this stat over time nicely for ya.

Bill Willits

Hey Aurimas.
I have found this code to be very useful. The prediction of catch-up time is remarkably accurate!
I created a script that add some bells and whistles – like notification via email during the catchup process and when fully caught up. The script relies on the heartbeat table for computing the lag so you need to have that.
I hope it is useful to others. (and , I hope this pastebin works).
http://pastebin.com/H2pxihrx

~Bill

Ross Carver

Aurimas – makes sense. I stumbled on this post when trying to diagnose a slave not catching up. For others and I believe it may be covered in other posts here – setting innodb_flush_log_at_trx_commit=0 helped a permanently lagging slave catch up quickly. I then set it back to 1 once it caught up and its fine and not lagging. HTH this helps someone else.

R

Joey Aldrin Cruz

Thanks Aurimas; I found this script very useful mostly when the times that the slave took so long to catch-up with the master. I also always answered IDK or it depends on what is the query is or how big is the query that is processing by the slave. When I used this script I can perfectly tell the ETA on when the slave can catch-up with the master. Thank you very much for this one! Kudos~!

sometimesomehow

The script is missing something.
I cannot reproduce the numbers in the output by hand.

Also, I do not get negative values for “speed” / “c_sec_s” when the replication falls farther behind as the example shows.

Ed Morley

There is a bug in the script – as noted in another comment, it doesn’t provide negative c_sec_s in some cases.

Notably the way speed and o_speed are calculated result in values where “1.0” means “just keeping up with new activity, not actually eating into the existing seconds behind”, which is contrary to the definition of c_sec_s on this page – and also means the ETAs are wrong.

I have an updated version which fixes the above, plus:
* Displays “Inf” if the current ETA is “will never catch up”.
* Switches the -W interactive to fflush(), since the former results in an error/warning on newer awk.
* Reduces the number of columns to improve readability.
* Adds a column separator between the first two columns and the rest.
* Uses hours rather than days for the ETA columns (if you’re that many days behind replicating that hours is too verbose, then you need to just perform another DB dump and start from scratch IMO).
* Replaces the grep invocation with awk matching, as suggested in a comment above.

See:
https://gist.github.com/edmorley/f8589f4d6fa84df4cce1a13cbac83d98

Aurimas

Nice work, Ed. Thanks a lot for an update.