MySQL relay log corrupted, how do I fix it? Tried but failed

Question

A MySQL v5.1.61 relay got corrupted when the machine suddenly shut down. I tried to fix it but it didn't work.
— How do I fix it? Did I do something wrong?

As far as I've read, corrupted MySQL relay logs are easily fixed:

change master to master_log_file='<Relay_Master_Log_File>',
                 master_log_pos=<Exec_Master_Log_Pos>;

where Relay_Master_Log_File and Exec_Master_Log_Pos are listed by:
mysql> show slave status;

However when I did change master status ..., I got a primary key violation error. How is that possible? Is the above procedure no correct, or is e.g. some +1 missing?

_{(For now I've simply re-imported a --master-data mysqldump from the master to the slave, and this solved the problem. However, in the future, doing that might not be appropriate.)}

Here follows details about my particular problem:

mysql> show slave status \G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: the-master-host
                  Master_User: replication
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000021
          Read_Master_Log_Pos: 33639968
               Relay_Log_File: mysql-relay-bin.000271
                Relay_Log_Pos: 2031587
        Relay_Master_Log_File: mysql-bin.000020
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB: the_database
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 1594
                   Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 66395191
              Relay_Log_Space: 36559177
              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: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 1594
               Last_SQL_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.

And this is what I did:

mysql> stop slave;
mysql> reset slave;
mysql> change master to master_host='the-master-host', master_user='replication', master_password='the-password', master_log_file='mysql-bin.000020', master_log_pos=66395191;
mysql> start slave;

And this is what happened, a PK error:

131122 15:17:29 [Note] Slave I/O thread: connected to master 'replication@the-master-host:3306',replication started in log 'mysql-bin.000020' at position 66395191
131122 15:17:29 [ERROR] Slave SQL: Error 'Duplicate entry '71373' for key 'PRIMARY'' on query. Default database: 'the_database'. Query: 'insert into ...  values ...', Error_code: 1062
131122 15:17:29 [Warning] Slave: Data truncated for column 'date' at row 1 Error_code: 1265
131122 15:17:29 [Warning] Slave: Duplicate entry '71373' for key 'PRIMARY' Error_code: 1062

I think I followed the recommended procedure (see links just below), still there was a PK error :-( ? http://bugs.mysql.com/bug.php?id=26489, search for "Workarounds". http://mhbarr.wordpress.com/2013/07/26/mysql-slave-corrupted-relay-log/ https://stackoverflow.com/a/14438408

Answer 1

Error: Last_SQL_Errno: 1594 Last_SQL_Error: Relay log read failure: Could not parse relay log event entry.

This error message means that the copy of the MySQL replication log could not be read on the slave server. A common cause of this is where a slave server has not been cleanly rebooted. In some cases it may mean that the replication log contains errors on the master server, but this is less common.

• Before doing anything backup all your databases, logs, image servers, repeat, several times, and only continue at your own risk.

** If you have MASTER-MASTER replication with additional SLAVE servers read through the notes at the bottom before continuing.

First run "show slave status \G" on the slave and note:

Relay_Master_Log_File: mysql-bin.000026
Exec_Master_Log_Pos: 1097157

First we want to make sure that the master log file is intact, so jump onto the master server and find the Relay_Master_Log_File (check /var/log/mysql) and run the following command:

mysqlbinlog mysql-bin.000026

The log will be displayed but hopefully you won't see any error messages. If you see error messages then the master logs are corrupt and you'll likely have to re-image - stop following this answer now.

Next run the same command on the slave relay log (often in /var/lib/mysql)

mysqlbinlog mysqld-relay-bin.000056

You will likely see some errors showing the corruption that has stopped replication, like this:

ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 336, event_type: 2
ERROR: Could not read entry at offset 1097414: Error in log format or read error.
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
root@db:/var/lib/mysql#

If you see any errors then the log is fine on the master and only the slave's relay log is corrupt. This is good news, we can reset the slave and tell it the masters details and where to continue from. If you don't see any errors then stop reading now, you have a different problem.

If the slave relay log has errors, run the following commands to reset the slave and corrupted logs reconnect to the master, get the ok logs and start slaving again. Note that MASTER_LOG_POS is the Exec_Master_Log_Pos, and MASTER_LOG_FILE is the Relay_Master_Log_File both from the first command.

mysql> stop slave;
Query OK, 0 rows affected (0.14 sec)

mysql> reset slave;
Query OK, 0 rows affected (0.43 sec)

mysql>  CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000026', MASTER_LOG_POS=1097157;
Query OK, 0 rows affected (0.93 sec)

mysql> start slave;
Query OK, 0 rows affected (0.00 sec)

The reset slave command clears the slave's local copy of the master logs and some configuration. The "CHANGE MASTER" command reconfigures the replication. When the slave is started it gets new logs from the master server and starts replicating again.

Your replication should now be fixed and your master servers in sync.

---

MASTER-MASTER-SLAVE Information:

Please note the following if you are using MASTER-MASTER with additional SLAVE servers (ie you are replicating data from the 2 Master servers to additional MySQL instances):

Setup example:

MASTER1 <> MASTER2 > SLAVE1

If you have master servers MASTER1 and MASTER2, with an additional slave server SLAVE1 replicating from MASTER2, and you have had to stop, reset and restart replication on MASTER2, the slave server SLAVE1 may now try and process records from the log file from MASTER1 that it has already processed.

This may happen if the slave server had processed records from the log files from MASTER1 before they were cleared and re-downloaded on MASTER2. Depending on replication latency and data volumes this may only be a few log entries, but only you know your data or the impact this may have on integrity.

If this happens you will likely see the slave servers stop replicating due to DUPLICATE KEY errors when they insert something they've already received.

You can either recreate the slave servers to ensure you have valid data integrity, or skip the errors caused by reprocessing updates until it starts processing new log entries. You could also have a look in the MySQL log files to see what updates it contains.

If you want to skip past the errors as the slave server processes the log to get new data you can run the following command on the slave:

stop slave ; SET GLOBAL sql_slave_skip_counter = 1; start slave;

In a recent case we had to skip past 10 duplicate entry errors on a slave server before it got to new data. After skipping the 10th duplicate key error the slave continued working and was in sync with both master servers.

If I were using a SLAVE server for backups I would consider that it's data integrity was critical and re-image from a master. Otherwise you can make a judgement based on the servers application as to whether skip the errors or run checks on the data.

Answer 2

[Fixing MySQL replication after slaves' relay log was corrupted]

MySQL replication on slave (version 5.XX) has stopped. Slave_IO_Running was marked as Yes, but Slave_SQL_Running as No. Simple stop/start slave didn’t help so further problem analysis was needed. It seemed that current slave’s relay log was corrupted because testing with “mysqlbinlog” has printed out an error. Therefore, the solution was to discard current relay binlogs and to point slave to the last master binlog position.

To fix the error, current binlog files on slave should be discarded and set new position. Before setting new binlog position it’s important to remember Relay_Master_Log_File and Exec_Master_Log_Pos values from corrupted slave server using command SHOW SLAVE STATUS \G:

Relay_Master_Log_File: mysql-bin.002045
Exec_Master_Log_Pos: 103641119

OK, with this values, new binlog position can be set:

# stop slave
mysql> stop slave;

# make slave forget its replication position in the master's binary log
mysql> reset slave;

# change slave to start reading from stopped position
mysql> change master to master_log_file='mysql-bin.002045', master_log_pos=103641119;

# start slave
mysql> start slave;

Just to note that reset slave will delete master.info, relay-log.info and all the relay log files, so it's not needed to clean leftovers in /var/lib/mysql directory.

Answer 3

I know it's been over a year, but here is what may have happened to this particular problem.

mysql> stop slave;
mysql> reset slave;
mysql> change master to master_host='the-master-host', master_user='replication', master_password='the-password', master_log_file='mysql-bin.000020', master_log_pos=66395191;
mysql> start slave;

That looks like that should have fixed it because it removed the corrupt relay log.

Then, you got a PK error 1062. Why ?

There is an outstanding bug (http://bugs.mysql.com/bug.php?id=60847) that still active in MySQL 5.5

Although the bug relates to using mysql --single-transaction --flush-logs, a related quirk exists.

I have seen that quirk on some EC2 servers running as Slaves for a client just last week in MySQL 5.5.15

On the Master, there was a weird multiple row extended INSERT where each tuple being inserted was a SELECT. What happened was that the LAST_INSERT_ID in the relay log, which forms the next auto increment to assign, was already in use on the Slave because of multiple-row inserts beforehand.

The serialized INSERT in the relay log looked like

INSERT INTO tablname (column,column) VALUES (value,value,...)

The column list did not include the numeric primary key. When the 1062 error came back, I would use the same query it failed on, run the query manually. It did not hit the 1062 error. Then, I ran the usual skip slave commands:

STOP SLAVE;
SET GLOBAL SQL_SLAVE_SKIP_COUNTER=1;
START SLAVE;
SET @sleepnumber = SLEEP(3);
SHOW SLAVE STATUS\G

Then, replication caught up.

My advice would be to properly serialize your INSERTs on the Master because this bug-like situation is actually quite avoidable.

Answer 4

You have done it quite right (as other already said).

The only issue is with master.info file (contains information about position in master's mysql-bin.log) because this file is not synced to disc after each query processed.

So your info about positions in master's log is outdated and you are processing already processed queries which needs to be skipped with SET GLOBAL SQL_SLAVE_SKIP_COUNTER=1;.

Unfortunately, if you use some queries like UPDATE table SET counter=counter+1 WHERE id = 12345 and using binlog_format=STATEMENT your databases may go out of sync, I think.

You can tell MySQL server to sync master.info after every event by setting up variable sync_master_info but it will probably have huge performance consequences.