MySQL slave taking too long on "Queueing master event to the relay log"

I have two mysql mysql slave servers. The DB version is:

mysql> show variables like '%version%';
+-------------------------+-----------------------------------------------------+
| Variable_name           | Value                                               |
+-------------------------+-----------------------------------------------------+
| innodb_version          | 1.1.8-rel29.4                                       |
| protocol_version        | 10                                                  |
| slave_type_conversions  |                                                     |
| version                 | 5.5.29-29.4-log                                     |
| version_comment         | Percona Server (GPL), Release rel29.4, Revision 401 |
| version_compile_machine | x86_64                                              |
| version_compile_os      | Linux                                               |
+-------------------------+-----------------------------------------------------+
7 rows in set (0.00 sec)

A developer had to rebuild a big table on master, after which the slave's status is shown as:

```
show slave status\G
1. row
Slave_IO_State: Queueing master event to the relay log
Master_Host: 10.140.10.31
Master_User: replicator
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000100
Read_Master_Log_Pos: 246814935
Relay_Log_File: relay-bin.000002
Relay_Log_Pos: 163153081
Relay_Master_Log_File: mysql-bin.000100
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB: temp
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:

If the large table was reload on the Master using LOAD DATA INFILE, then here's what's happening:

• The relay logs are being used to transport the entire input file.

• The input file has to be extracted from the relay logs into a temp file.

• The Slave must execute LOAD DATA INFILE against the extracted temp file.

I have described this process in the DBA StackExchange before

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

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

• May 04, 2014 : MySQL 5.6 showing wrong "second_behind_master"

You have to let MySQL Replication complete this process.

UPDATE 2014-09-07 15:40 EDT

I have a working theory that might uncover why relay log are growing, causing lots of write I/O, and Seconds_Behind_Master is still 0.

If your binlog_format is set to ROW or MIXED, my gut feeling is that all the rows making up the SELECT are being embedded into the relay logs in the same fashion as I described LOAD DATA INFILE, but not with the same mechanism. Why ?

LOAD DATA INFILE embeds the CSV file in binlog event chunks to allow extraction and manifestation of the CSV file in the Slave. The INSERT ... SELECT would have to treat the SELECT as a single transaction. Then, import all the row changes as part of the INSERT. In order to accomplish that, Master and Slave would have to be using binlog_format ROW or MIXED. If you were using binlog_format STATEMENT, the statement would land in the slave's relay logs instantly and the Seconds_Behind_Master would have to start climbing immediately.

This is my suspicion because of what the MySQL Documentation says about INSERT ... SELECT


Due to this issue, beginning with MySQL 5.6.4, INSERT ... SELECT ON DUPLICATE KEY UPDATE and INSERT IGNORE ... SELECT statements are flagged as unsafe for statement-based replication. With this change, such statements produce a warning in the log when using statement-based mode and are logged using the row-based format when using MIXED mode. (Bug #11758262, Bug #50439)

This takes a whole new perspective when you look at those bug reports

When MySQL 5.5.18 was released, this bug was supposed to be fixed


Bugs Fixed



-
Incompatible Change: Replication: The statements in the
following list are now marked as unsafe for statement-based
replication. This is due to the fact that each of these
statements depends on the results of a SELECT statement whose
order cannot always be determined. When using STATEMENT
logging mode, a warning is issued in the binary log for any of
these statements; when using MIXED logging mode, the statement
is logged using the row-based format.



-
INSERT ... SELECT ... ON DUPLICATE KEY UPDATE

-
REPLACE ... SELECT

-
CREATE TABLE ... IGNORE SELECT

-
CREATE TABLE ... REPLACE SELECT

-
INSERT IGNORE ... SELECT

-
UPDATE IGNORE
When upgrading, you should note the use of these statements in
your applications, keeping in mind that a statement that
inserts or replaces rows obtained from a SELECT can take up
many times as much space in the binary log when logged using
row-based format than when only the statement itself is
logged. Depending on the number and size of the rows selected
and inserted (or replaced) by any such statements, the
difference in size of the binary log after the logging of
these statements is switched from statement-based to row-based
can potentially be several orders of magnitude. See Section
15.1.2.1, "Advantages and Disadvantages of Statement-Based and
Row-Based Replication." (Bug #11758262, Bug #50439)



Did you see that part that says

a statement that
inserts or replaces rows obtained from a SELECT can take up
many times as much space in the binary log when logged using
row-based format than when only the statement itself is
logged. Depending on the number and size of the rows selected
and inserted (or replaced) by any such statements, the
difference in size of the binary log after the logging of
these statements is switched from statement-based to row-based
can potentially be several orders of magnitude

This could be happening because you are either using a version of MySQL before 5.5.18 or a version of MySQL that missed this patch.

If you switch to binlog_format STATEMENT, this phenomenon of growing relay logs, high disk I/O, and Seconds_Behind_Master still being 0 should disappear. Either that or upgrade your MySQL.

UPDATE 2014-09-08 08:06 EDT

Let me make a clarification. Personally, I do not like binlog_format ROW because of how bloated binary and relay logs become. In this post, I said use STATEMENT. That's just my preference. The more correct for me to say is : make the Master and its Slaves have the exact same binlog_format. Just make everything MIXED. You will have to bite the bullet and resync the Slave from scratch.

StackExchange Database Administrators Q#75743, answer score: 3