I've got a vanilla MySQL replication, using "MIXED" mode.

The mysql slave lag calculation behaves very strangely - one moment it is 0 and the one after it it's 3630 seconds (or a similar number), then back to 0, and so on and so forth. Obviously, something is wrong in the replication configuration, since MySQL computes the lag based on the timestamps in the relay log.

I've tried checking the time of the servers, which is identical (using SELECT NOW() in MySQL). I've also checked the timezone (SELECT @@system_time_zone) which is set to CDT on both master and slave.

What else can I verify to make sure this issue is resolved? Did anyone else encounter this problem?

  • Maybe better asked on ServerFault.com
    – Michael
    Commented Jun 2, 2011 at 14:03
  • I've encountered this before. I've maintained about 40 MySQL slave servers and seen this problem on two of them. It didn't seem to affect performance in any way - just the output of seconds_behind_master was displayed incorrectly.
    – Matt Healy
    Commented Jun 2, 2011 at 14:04
  • I've been asking questions of the sort on ServerFault for a while, but here I get answers faster, and from more people...
    – shlomoid
    Commented Jun 2, 2011 at 14:06

2 Answers 2


MySQL Replication performs weird calculations for Seconds_Behind_Master based on a few things.

  • What NOW() returns for SQL run on the master as recorded in relay logs
  • What NOW() returns on the slave
  • The last position from the master that was executed

Here is a SHOW SLAVE STATUS\G and how to identify the Last Executed SQL from the Master

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_User: replicant
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.002814
          Read_Master_Log_Pos: 823078734
               Relay_Log_File: relay-bin.007364
                Relay_Log_Pos: 823078879
        Relay_Master_Log_File: mysql-bin.002814
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
                   Last_Errno: 0
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 823078734
              Relay_Log_Space: 823079071
              Until_Condition: None
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
        Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
               Last_SQL_Errno: 0
1 row in set (0.00 sec)

Notice the following fields in SHOW SLAVE STATUS\G

  • Master_Log_File (Line 6) : Log File on the Master whose position was last read
  • Read_Master_Log_Pos (Line 7) : Last position read on the Slave from the Master
  • Relay_Master_Log_File (Line 10) : Log File on the Master whose position was last executed
  • Exec_Master_Log_Pos (Line 22) : Last position executed on the Slave from the Master
  • Relay_Log_Space (Line 23) : Sum of bytes from all relay logs

To calculate Seconds_Behind_Master, it would essentially figured out

NOW() as recorded in Master LogFile 'Master_Log_File' LogPos 'Read_Master_Log_Pos'
NOW() on the Slave

This number can intermittently grow because the I/O thread can collect more entries from the Master and loading it into the last relay log while processing the SQL statement located at Master LogFile 'Relay_Master_Log_File' and Master LogPos 'Exec_Master_Log_Pos'. This increasing number is also manifested by three(3) variables changing: Relay_Log_Space, Master_Log_File, Read_Master_Log_Pos. If Seconds_Behind_Master is 0, this is good indication that Read_Master_Log_Pos and Exec_Master_Log_Pos virtually the same. Also worth noting is the fact that long running SQL can fool you into thinking that replication is behind. Once that SQL statement is complete and no other statements have sufficiently backlogged, Seconds_Behind_Master can drop dramatically, even to 0.

So, why would Seconds_Behind_Master bounce back and forth between 0 and an increasing number. It is possible for network latency in transmitting SQL through the I/O thread to contribute to miscalculation because the needed TIMESTAMP variable was not reached yet in the back of the last relay log (remember this is asynchronous replication). To verify this, run mysqlbinlog against any binary log or relay log and see where the TIMESTAMP variables are written between statements.

This behavior was first addressed June 22, 2007 and the bug was supposedly fixed then.

Here is one sure way to take MySQL Replication and screw its head on correctly (For this example, use the same SHOW SLAVE STATUS\G)

Using Relay_Master_Log_File mysql-bin.002814 and Exec_Master_Log_Pos 823078734 as the Log FilePosition to Restart From, run these commands


These steps should 1) kill both I/O and SQL Threads, 2) wipe out All Collected Relay Logs, 3) start with a New Relay Log, and 4) establish New I/O and SQL Threads.

Replication should be good to go from here. As to whether or not this bug can truly be addressed, this now in Oracle's hands (That last statement does not inspire any confidence, does it ???)

  • Restarting the replication from the same place like you suggested, worked great. Thanks! I am still clueless to what caused this problem to begin with... Oh well. :)
    – shlomoid
    Commented Jul 18, 2011 at 8:25
  • @shlomoid : What is more disturbing is that the problem was claimed to have been fixed. So, MySQL (eh Oracle) is even more clueless and they have the source code. Commented Jul 18, 2011 at 11:14
  • I've seen useless answers and even comments on answers that include no insight get upvoted, yet this answer's not noticed by the community at all. It's a decent answer deserving to be upvoted and highlighted.
    – uygar.raf
    Commented Jul 19, 2011 at 8:01

This still happens in MySQL 5.1 now in 2013. I found this occurs when something causes the slave to go far behind (such as taking a slave offline for maintenance). When it catches up again and can be used, it tends to display erratic behaviour jumping from 0 to 40+ and back again, which can throw off monitoring tools.

The very simple solution in this case is to issue slave stop; slave start;

This resets the values. I can see that when you were 60,000 seconds behind, after being caught up one could be =~ 60 second off. Stop/starting from point blank range makes sense.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.