The Seconds_Behind_Master is really like viewing the past via time travel.
Think of it this way:
- The Sun is 93,000,000 miles away from the Earth
- The speed of light is 186,000 miles/sec
- Simple division shows that it takes roughly 500 sec (8 min 20 sec) for the Sun's light to reach Earth
- When you look at the Sun, you actually don't see the Sun. You see where it was 8 min 20 sec ago.
In like manner, it seems that the Master is processing a lot of queries at the same time.
You look back at the Slave, run
SHOW SLAVE STATUS\G and it says 200 for
Seconds_Behind_Master. How is that number calculated? Slave's Clock Time (UNIX_TIMESTAMP(NOW()) - TIMESTAMP of the Query when it was completed and recorded in the Master's Binary Log.
There is another metric to look at besides
Seconds_Behind_Master. That metric is called
Relay_Log_Space. That represents the sum of all bytes for all relay files on the Slave. By default, the largest single relay log is limited to 1GB. If
Relay_Log_Space is less than 1GB, this indicates that many long running queries executed on the Master in parallel. Unfortunately, due to the single-threaded nature Replication's SQL thread, queries are executed one behind the other.
For example, suppose you have the following scenario on the Master:
- Slow Query log is enabled
- 20 queries executed in parallel on the Master
- Each query took 3 seconds
- Each query get recorded in the Master Binary Log with the same timestamp
When the Slave reads those queries from its relay log and processes them one by one
- the Slave's Clock will be moving
- the TIMESTAMP for each of the 20 queries will be identical
- the difference will increasing 3 seconds be completed query
- this results in 60 seconds for
Concerning the Slow Log, the default for long_query_time is 10 seconds. If all your queries in the relay logs are less than 10 seconds, you will never catch anything in the Slow Query Log.
I have the following recommendations for both Master and Slave servers
- RECOMMENDATION #1 : Upgrade to MySQL 5.5. Under MySQL 5.5 and Percona Server 5.1.38+, you can tune InnoDB to access multiple CPUs. I have written past posts about this
- RECOMMENDATION #2 : Use InnoDB for all tables. InnoDB caches data and indexes in RAM, MyISAM only caches indexes.
- RECOMMENDATION #3 : Increase RAM. You must cache more data and indexes on the Slave and Master alike
- RECOMMENDATION #4 : Tune all queries. Reducing milliseconds from queries that run hundreds of times goes a long way to reduce
If you want to see the queries causing the replciation lag, do the following:
SHOW SLAVE STATUS\G
- Get name of relay log from
- In the OS,
cd /var/lib/mysql or wherever the relay logs are written
- Dump the relay log to a text file
For example, Let's do
SHOW SLAVE STATUS\G
Slave_IO_State: Waiting for master to send event
If I run
STOP SLAVE; START SLAVE;, the relay log closes and a new one is open. Yet, you want
Dump the contents as follows:
mysqlbinlog relay-bin.000030 > /root/RelayLogQueries.txt
You can now see the queries the Slave is currently trying to process. You can use those queries as the starting point for tuning.