MySQL 5.6 showing wrong "second_behind_master"

```
mysql> show slave status\G
1. row
Slave_IO_State: Waiting for master to send event
Master_Host: 10.10.7.98
Master_User: replication
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000032
Read_Master_Log_Pos: 277431436
Relay_Log_File: mysqld-relay-bin.000039
Relay_Log_Pos: 143474118
Relay_Master_Log_File: mysql-bin.000031
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 963696099
Relay_Log_Space: 530952469
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 98
Master_UUID:
Master_Info_File: /mnt/vol1/mysql/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: updating
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set:
Executed_Gtid_Set:
A

The Seconds_Behind_Master may be zero, but you should be looking at other parts of the SHOW SLAVE STATUS\G because it can tell you something about why it's zero. Let's discuss three(3) aspects that will shed some light on Replication's Seconds_Behind_Master.
ASPECT #1

There are occasions when a group of SQL commands are executed individually in the same one-second timeframe. Why does this happen on a Slave?

Keep in mind that the Master may have executed many INSERTs, UPDATEs, and DELETEs, in parallel. However, the binary logs records them as serialized events. An event will include the TIMESTAMP of the SQL command followed by the SQL Command.

If 30 DML commands each took 1 second to complete on a Master at 1399212601 (2014-05-04 10:10:01), they get recorded in the binary logs with the timestamp 1399212601.

On the Slave, when each command is read one-by-one, the timestamp will be 1399212601 for each command. Yet, real-time clock on the server will be steadily increasing. Seconds_Behind_Master is nothing more than UNIX_TIMESTAMP(NOW()) - 1399212601. This is the manifestation of Replication Lag.
ASPECT #2

There are occasions when a group of SQL commands are executed as series of row changes.
This could easily happen with row based replication (binlog_format is set to ROW instead of STATEMENT). Individual row changes bloat binary logs and result in same replication lag as stated in ASPECT #1
ASPECT #3

Here are three posts where I discuss how Replication handles LOAD DATA INFILE

• Apr 18, 2013 : Loading data in mysql using LOAD DATA INFILE, replication safe?

• Apr 02, 2013 : MySQL slave stuck in "Reading event from the relay log"?

• Jan 22, 2012 : MySql shell command not replicated to slave

When you execute LOAD DATA INFILE on a Master, the Master will copy the entire CSV file as binlog events into the Binary Logs. The next binlog event recorded is the LOAD DATA INFILE command itself.

The Slave will see a binlog event in its relay logs that will alert the Slave to read the entire CSV file. Then, when it see the LOAD DATA INFILE, it executes it against the temp CSV file in created.

During the manifestation of the temp CSV file, the Seconds_Behind_Master will read 0. Then, when the entire CSV file is made and the LOAD DATA INFILE begins execution, the Seconds_Behind_Master will just increase by 1 or 2. It will do a punctuated jump to hundreds or even thousands of seconds.
SUMMARY

Binary Logs are are to handle group commits for better performance. Notwithstanding, you should looking at the following

• Master_Log_File : Binary Log of the Last Binlog Event recorded on the Master read on the Slave

• Read_Master_Log_Pos : Position of Last Binlog Event that was read from the Master and written to Relay Log on the Slave

• Relay_Master_Log_File : Binary Log of the Last Binlog Event that was read from Master and was executed on Slave

• Exec_Master_Log_Pos : Position of the Last Binlog Event that was read from Master and was executed on Slave

• Relay_Log_Space

If the Relay_Log_Space is changing, then the IO Thread is reading just fine from the network. You can also see that by watching either Master_Log_File or Read_Master_Log_Pos or both changing.

If the Relay_Master_Log_File and/or Exec_Master_Log_Pos is changing, then the command are begin executed on the Slave.

Therefore, once Seconds_Behind_Master is 0 for a long time, look for changes in these five fields in the SHOW SLAVE STATUS\G.

StackExchange Database Administrators Q#64444, answer score: 3