MySQL replication duplicate key errors after error 1594

MySQLreplication

So I had this happen to me recently:

mysql> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 198.101.212.103
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 10
              Master_Log_File: mysql-bin.000103
          Read_Master_Log_Pos: 30051137
               Relay_Log_File: mysqld-relay-bin.000095
                Relay_Log_Pos: 23511387
        Relay_Master_Log_File: mysql-bin.000095
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB:
          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: 23511241
              Relay_Log_Space: 477287485
              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.
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 1

So I looked at master:

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000103 | 30007591 | xxx_l       |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

Everything fine. So I ran:

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

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

mysql> change master to master_log_file='mysql-bin.000095', master_log_pos=23511241;
Query OK, 0 rows affected (0.02 sec)

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

As suggested by everyone and now I run into:

mysql> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 198.101.212.103
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 10
              Master_Log_File: mysql-bin.000103
          Read_Master_Log_Pos: 30763976
               Relay_Log_File: mysqld-relay-bin.000003
                Relay_Log_Pos: 58516
        Relay_Master_Log_File: mysql-bin.000091
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB:
          Replicate_Ignore_DB:
           Replicate_Do_Table:
       Replicate_Ignore_Table:
      Replicate_Wild_Do_Table:
  Replicate_Wild_Ignore_Table:
                   Last_Errno: 1062
                   Last_Error: Error 'Duplicate entry '128776' for key 'PRIMARY'' on query. Default database: 'xxx_l'. Query: 'INSERT INTO images ...'
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 58370
              Relay_Log_Space: 684452249
              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: 1062
               Last_SQL_Error: Error 'Duplicate entry '128776' for key 'PRIMARY'' on query. Default database: 'xxx_l'. Query: 'INSERT INTO images ...'
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 1
1 row in set (0.00 sec)

Obviously my replication is now broken beyound repair. Considering every answer says that it is safe to replicate from the last master position why did this not work?

As a side note: if I do not have to reimage let me know.

Best Answer

How I would do it, without having to reload all data:

Take the slave out of production- it has drifted and has wrong data
Skip replication errors until the replication is running again (but remember, with wrong data) with slave-skip-errors. Not always possible.
Use pt-table-checksum to identify the master-slave differences
Use pt-table-sync on the particular table(s) to fix the errors. Both of those tools are harder to use when using filtering.
You now have a consistent replication (for a while - you should identify the underlying problem that cause it at first)

Considering every answer says that it is safe to replicate from the last master position why did this not work?

This is not a sane MySQL advice. Full stop.

I cannot say for sure, but if that when you have filtering, my experience says that that is the 90% of the root cause for replication problems. There are many reasons to not use master-side filtering while having the same results (replication breaking, difficult to synchronize them, impossible to promote a slave as master, etc.). Other options include the loss or corruption of the relay logs.

Related Solutions

Mysql – Looking for an efficient way to fix “Could not parse relay log event entry…” error

There is more stable approach you can try

Here is something to remember

Whenever you run CHANGE MASTER TO, it will erase every relay log you have. You do not want to keep relay logs of commands you have not executed any SQL on as of yet

The following is an excerpt taken from a post I made back on Feb 03, 2012 : How to resolve the master server shut down/unavailability in mysql with master - slave replication :

Please notice that there are two sets of replication coordinates from the Master

(Master_Log_File,Read_Master_Log_Pos)

(Relay_Master_Log_File,Exec_Master_Log_Pos)

There is a major difference between them

(Master_Log_File,Read_Master_Log_Pos) tells you the last binlog statement from the Master's log file and log position that the Slave read from the Master and placed in its Relay Logs.

(Relay_Master_Log_File,Exec_Master_Log_Pos) tells you the last binlog statement from the Master's log file and log position that the Slave read from the Master and placed in its Relay Logs THAT IS NEXT TO BE EXECUTED ON THE SLAVE.

What you want are two things:

Erase Every Binary Log You Have
Start Collecting Binary Log Entries From the Last SQL You Successfully Executed.

In your case, you must use the second set of Replication Coordinates

Relay_Master_Log_File
Exec_Master_Log_Pos

It is easy to distrust a corrupt relay log as shown in the error message. The one that hurts the most is a corrupt Master Log. You will have to jump through hoops if that is the case. On the other hand, if one of the other situations was the reason for the corrupt relay log, the simplest and most concise approach is what I stated.

To make sure, whatever is reported for Relay_Master_Log_File, if that particular binary log still exists on the Master, perform a mysqlbinlog on it. If it dumps in its entirety without corrupt characters, go ahead and use the second set of replication coordinates.

From my same earlier post

mysql> show slave status\G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 10.48.20.253
                Master_User: replicant
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000254
        Read_Master_Log_Pos: 858190247
             Relay_Log_File: relay-bin.066069
              Relay_Log_Pos: 873918
      Relay_Master_Log_File: mysql-bin.000254
           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: 858190247
            Relay_Log_Space: 873772
            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
1 row in set (0.00 sec)

notice that the Replication Coordinates from SHOW SLAVE STATUS\G for what was last executed are (mysql-bin.000254,858190247). The CHANGE MASTER TO command in this case would be:

CHANGE MASTER TO master_log_file='mysql-bin.000254',master_log_pos=858190247;

Give it a Try !!!

UPDATE 2012-09-14 16:38 EDT

If you worried about the stockpiling relay logs, just throttle the relay logs. In SHOW SLAVE STATUS\G, there is a field called Relay_Log_Space. That gives you the sum of all relay sizes in bytes. Did you know you could put a cap on that number ?

The option is called relay_log_space_limit.

For example, if you want to cap the total number of bytes to 10G, do the following

STEP 01) Add this to /etc/my.cnf on the Slave

[mysqld]
relay_log_space_limit = 10G

STEP 02) Run service mysql restart on the Slave

and that's it !!!

When the oldest relay has all its entries processed, it is deleted and a new relay log is created. That gets filled until all relay logs add up to 10G. That's the only way to control runaway relay log space issues.

UPDATE 2012-09-14 18:10 EDT

SUGGESTION : If you make mysqldump backups of the data on the Slave every midnight, you could set up the following to restrict having 1TB of binary logs:

STEP 01) Add this to /etc/my.cnf on the Master

[mysqld]
expire_logs_days = 14

STEP 02) Run this query on the Master

mysql> PURGE BINARY LOGS BEFORE DATE(NOW()) - INTERVAL 14 DAY;

STEP 03) service mysql restart on the Master

STEP 04) Add a mysqldump backup script to a crontab on the Slave

This will make the Slave more useful and would control having excess binary logs to worry about

MySQL slave replicates changes that are in neither binlog_do_db nor replicate_do_db

Replication filtering isn't bulletproof. Due to how the filtering is implemented the events responsible for your errors are being generated because the default database at query runtime is the my-database schema as expected and the query being executed is fully qualified INSERT INTO phpmyadmin.pma_column_info...

Peter Zaitsev explains the scenario well in this post:

Filtered MySQL Replication