23

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

  • 1
    Yes, it looks like it should have worked, and actually it looks like it probably actually did work, as perhaps the original relay log, before the corrupt section, had already done the insert at that master log position, but couldn't advance the displayed master position to the next pointer, since that pointer is stored in the relay log (which was corrupt.) So you might have gotten away with skipping that event and moving to the next event, then verifying that master and slave actually had identical data... I haven't had an opportunity to review the question in sufficient detail, yet. – Michael - sqlbot Nov 25 '13 at 15:09
  • 1
    Thanks @Michael-sqlbot, then I think that if this problem happens again, I'll do SET GLOBAL sql_slave_skip_counter = 1; START SLAVE; and skip one event on the slave, and hope that helps — does that make sense? If it doesn't help (if there's still a PK error), I'll import a dump with --master-data again. – KajMagnus Nov 25 '13 at 15:44
30

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

This error means that either the master log file is corrupted or the relay log file is corrupted.

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

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

Master_Log_File: mysql-bin.000026
Read_Master_Log_Pos: 2377104
Relay_Log_File: mysqld-relay-bin.000056
Relay_Log_Pos: 1097303
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.

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 (NOT the first one, which matches relay logs that have been fetched and need to be thrown away) both from the first command.

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

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

mysql>  CHANGE MASTER TO MASTER_HOST='master.host.com', MASTER_USER='masteruser', MASTER_PASSWORD='masterpass', 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)
  • 2
    Hi, thanks for your answer. If you read the question carefully, you'll notice it says "Relay log corrupted" — that's because we had already used mysqlbinlog in the manner you suggest, and found out that the relay log (not the master log) had been corrupted. Concenring the fix you suggest — if you read the question carefully, you'll notice that the fix you suggest is exactly what we had already attempted. But that did not work, and that is what the question is about. — But your answer might be useful for other people with a similar problem. – KajMagnus Aug 28 '14 at 18:28
  • 2
    It should probably be noted, that MASTER_LOG_FILE in CHANGE MASTER should be taken from Relay_Master_Log_File and not from Master_Log_File. Usually they will be the same but it might not be the case always (see percona.com/blog/2008/07/07/… ). – brablc Feb 3 '16 at 10:07
  • @brablc is right. Relay_Master_Log_File must be used, not Master_Log_File. See also: percona.com/blog/2008/07/07/… – Mircea Vutcovici Sep 6 '16 at 15:31
  • in most cases, there's no need for reset slave all because the master settings don't need to be changed (e.g. master_host, master_user, master_password), only MASTER_LOG_FILE and MASTER_LOG_POS, then a reset_slave should suffice – ympostor Jul 14 '17 at 3:15
  • This question and answer have saved my butt several times already. Thank you. – Artem Russakovskii Jun 2 at 23:29
7

[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.

  • 1
    Good answer - usually we don't need to change master host, password etc. Thx! – andy250 Feb 27 at 11:46
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.

1

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.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

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