Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-8507

gtid_ignore_duplicates doesn't work with log_slave_updates and multi-source replication

    XMLWordPrintable

    Details

      Description

      When log_slave_updates is enabled, gtid_ignore_duplicates doesn't appear to work with multi-source replication.

      When using a circular replication topology, this means some transactions may be executed twice.

      Let's say we have a topology like this using multi-source replication:

      master101 <=> master102 <=> master105 <=> master101

      master101 and master102 are running MariaDB 10.1.5.

      master105 is running MariaDB 10.0.20.

      Let's insert some data on master101:

      MariaDB [(none)]> INSERT INTO db1.test_table (str) VALUES ('str8');
      Query OK, 1 row affected (0.02 sec)

      Now lets see if the slaves are functional.

      master101 looks OK:

      MariaDB [(none)]> show slave 'master102' status\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 192.168.1.102
                        Master_User: repl
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: localhost-bin.000002
                Read_Master_Log_Pos: 485
                     Relay_Log_File: localhost-relay-bin-master102.000002
                      Relay_Log_Pos: 621
              Relay_Master_Log_File: localhost-bin.000002
                   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: 485
                    Relay_Log_Space: 932
                    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: 2
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: Current_Pos
                        Gtid_IO_Pos: 1-1-10,3-3-8
            Replicate_Do_Domain_Ids: 
        Replicate_Ignore_Domain_Ids: 
                      Parallel_Mode: conservative
      1 row in set (0.00 sec)
       
      MariaDB [(none)]> show slave 'master105' status\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 192.168.1.105
                        Master_User: repl
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: localhost-bin.000004
                Read_Master_Log_Pos: 501
                     Relay_Log_File: localhost-relay-bin-master105.000002
                      Relay_Log_Pos: 637
              Relay_Master_Log_File: localhost-bin.000004
                   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: 501
                    Relay_Log_Space: 948
                    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: 3
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: Slave_Pos
                        Gtid_IO_Pos: 1-1-10,3-3-8
            Replicate_Do_Domain_Ids: 
        Replicate_Ignore_Domain_Ids: 
                      Parallel_Mode: conservative
      1 row in set (0.00 sec)

      master102 looks OK too:

      MariaDB [(none)]> show slave 'master101' status\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 192.168.1.101
                        Master_User: repl
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: localhost-bin.000002
                Read_Master_Log_Pos: 485
                     Relay_Log_File: localhost-relay-bin-master101.000002
                      Relay_Log_Pos: 776
              Relay_Master_Log_File: localhost-bin.000002
                   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: 485
                    Relay_Log_Space: 1087
                    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: 1
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: Current_Pos
                        Gtid_IO_Pos: 1-1-10,3-3-8
            Replicate_Do_Domain_Ids: 
        Replicate_Ignore_Domain_Ids: 
                      Parallel_Mode: conservative
      1 row in set (0.00 sec)
       
      MariaDB [(none)]> show slave 'master105' status\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 192.168.1.105
                        Master_User: repl
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: localhost-bin.000004
                Read_Master_Log_Pos: 501
                     Relay_Log_File: localhost-relay-bin-master105.000002
                      Relay_Log_Pos: 792
              Relay_Master_Log_File: localhost-bin.000004
                   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: 501
                    Relay_Log_Space: 1103
                    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: 3
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: Slave_Pos
                        Gtid_IO_Pos: 1-1-10,3-3-8
            Replicate_Do_Domain_Ids: 
        Replicate_Ignore_Domain_Ids: 
                      Parallel_Mode: conservative
      1 row in set (0.00 sec)

      master105 got a duplicate key error from master102:

      MariaDB [(none)]> show slave 'master101' status\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 192.168.1.101
                        Master_User: repl
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: localhost-bin.000002
                Read_Master_Log_Pos: 485
                     Relay_Log_File: localhost-relay-bin-master101.000002
                      Relay_Log_Pos: 776
              Relay_Master_Log_File: localhost-bin.000002
                   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: 485
                    Relay_Log_Space: 1087
                    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: 1
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: Slave_Pos
                        Gtid_IO_Pos: 1-1-10,3-3-8
      1 row in set (0.00 sec)
       
      MariaDB [(none)]> show slave 'master102' status\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 192.168.1.102
                        Master_User: repl
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: localhost-bin.000002
                Read_Master_Log_Pos: 485
                     Relay_Log_File: localhost-relay-bin-master102.000002
                      Relay_Log_Pos: 621
              Relay_Master_Log_File: localhost-bin.000002
                   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: Could not execute Write_rows_v1 event on table db1.test_table; Duplicate entry '8' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log localhost-bin.000002, end_log_pos 458
                       Skip_Counter: 0
                Exec_Master_Log_Pos: 330
                    Relay_Log_Space: 1087
                    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: Could not execute Write_rows_v1 event on table db1.test_table; Duplicate entry '8' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log localhost-bin.000002, end_log_pos 458
        Replicate_Ignore_Server_Ids: 
                   Master_Server_Id: 2
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: Slave_Pos
                        Gtid_IO_Pos: 1-1-10,3-3-8
      1 row in set (0.00 sec)

      Looking at the relay log on master105 from master101, we see:

      #150720 13:29:57 server id 1  end_log_pos 368   GTID 1-1-10
      /*!100001 SET @@session.gtid_domain_id=1*//*!*/;
      /*!100001 SET @@session.server_id=1*//*!*/;
      /*!100001 SET @@session.gtid_seq_no=10*//*!*/;
      BEGIN
      /*!*/;
      # at 659
      # at 710
      #150720 13:29:57 server id 1  end_log_pos 419   Table_map: `db1`.`test_table` mapped to number 18
      #150720 13:29:57 server id 1  end_log_pos 458   Write_rows: table id 18 flags: STMT_END_F
      ### INSERT INTO `db1`.`test_table`
      ### SET
      ###   @1=8
      ###   @2='str8'
      # at 749
      #150720 13:29:57 server id 1  end_log_pos 485   Xid = 39
      COMMIT/*!*/;
      DELIMITER ;
      # End of log file
      ROLLBACK /* added by mysqlbinlog */;
      /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
      /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

      Looking at the relay log on master105 from master102, we see:

      #150720 13:29:57 server id 1  end_log_pos 368   GTID 1-1-10
      /*!100001 SET @@session.gtid_domain_id=1*//*!*/;
      /*!100001 SET @@session.server_id=1*//*!*/;
      /*!100001 SET @@session.gtid_seq_no=10*//*!*/;
      BEGIN
      /*!*/;
      # at 659
      # at 710
      #150720 13:29:57 server id 1  end_log_pos 419   Table_map: `db1`.`test_table` mapped to number 18
      #150720 13:29:57 server id 1  end_log_pos 458   Write_rows: table id 18 flags: STMT_END_F
      ### INSERT INTO `db1`.`test_table`
      ### SET
      ###   @1=8
      ###   @2='str8'
      # at 749
      #150720 13:29:57 server id 1  end_log_pos 485   Xid = 32
      COMMIT/*!*/;
      DELIMITER ;
      # End of log file
      ROLLBACK /* added by mysqlbinlog */;
      /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
      /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

      The GTID information appears to be identical between the relay logs. However, MariaDB is executing both transactions, rather than ignoring one of them.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              knielsen Kristian Nielsen
              Reporter:
              GeoffMontee Geoff Montee
              Votes:
              2 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: