kine always cause 1032 error in mysql slave mode

[9nix00]

Dear all,

recently we found when we work k3s with mysql replica mode. the kine always show errors like this:

          Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 1032
                   Last_Error: Could not execute Delete_rows event on table kube_prod.kine; Can't find record in 'kine', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000051, end_log_pos 19635315
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 19486733
              Relay_Log_Space: 22739548
              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: 1032
               Last_SQL_Error: Could not execute Delete_rows event on table kube_prod.kine; Can't find record in 'kine', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000051, end_log_pos 19635315
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 1

currently we use skip-slave-errors argument to skip this error, but we want know what happend and how to aviod this problem.

[brandond]

Kine doesn't support operating against a read-only replica. All servers should connect to a replica that is writable.

[9nix00]

hi @brandond , we use kine to connect the mysql master node, the slave is only used for backup, we only set the master ip to k3s.

current architecture:

k3s -connect-> mysql-01(master) -replica-> mysql-02(slave).

k3s still works well but mysql-02 slave status is stopped.

[brandond]

Have you raised the auto_increment_increment on the master? See #71 (comment)

Other than that I can't think of anything. We just use standard SQL to interact with the database. Do you maybe need to adjust some of the binlog sizes or something? We don't have any specific guides for setting this up; kine is frequently used against AWS RDS and it works fine without any extra tuning.

[9nix00]

no, we only use one master & one slave.

we will continue to pay attention to this issue.

we also use RDS and other cloud platform Native MySQL, all of them works fine.
I will try to review the slave log to confirm what happend. the cloud provider native mysql is more stronger than community.

[till]

Has anyone given any thought for r/w splitting in kine?

For example, to be able to utilize replicas for read ops while committing against the primary for all writes?

Wondering if this would be acceptable at all to attempt this or if there's a technical reason to not support it?

[brandond]

The golang SQL bindings don't support this last time I checked, so we would have to do our own management of separate connection pools. Not worth it as far as I can tell.

[till]

Makes sense. Would you be open to a more higher level solution like ent? As a abstraction across the sql drivers. Or additional code to support multiple DSNs?

[9nix00]

Dear all,

Recently, we have been working on some database recovery tasks and we have noticed that the same issue keeps recurring.

mysql version: 5.7.36-log

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 10.40.1.2
                  Master_User: sync
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000003
          Read_Master_Log_Pos: 313613925
               Relay_Log_File: mysql-relay-bin.000002
                Relay_Log_Pos: 151945365
        Relay_Master_Log_File: mysql-bin.000003
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
              Replicate_Do_DB: 
          Replicate_Ignore_DB: mysql,test,information_schema
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 1062
                   Last_Error: Could not execute Write_rows event on table kube_prod.kine; Duplicate entry '/registry/events/HIDDEN-VALUE-IN-ISSUE' for key 'kine_name_prev_revision_uindex', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000003, end_log_pos 168394293
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 168392012
              Relay_Log_Space: 297167485
              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 event on table kube_prod.kine; Duplicate entry '/registry/events/HIDDEN-VALUE-IN-ISSUE' for key 'kine_name_prev_revision_uindex', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log mysql-bin.000003, end_log_pos 168394293     
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 1
                  Master_UUID: 9556b7f7-373c-11ec-b1c5-e43d1a55c65e
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State:
           Master_Retry_Count: 86400
                  Master_Bind:
      Last_IO_Error_Timestamp:
     Last_SQL_Error_Timestamp: 240424 00:57:21
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set: 9556b7f7-373c-11ec-b1c5-e43d1a55c65e:6763-85155
            Executed_Gtid_Set: 9556b7f7-373c-11ec-b1c5-e43d1a55c65e:1-50668
                Auto_Position: 1
         Replicate_Rewrite_DB:
                 Channel_Name:
           Master_TLS_Version:

So, I check the binlog position:

 mysqlbinlog mysql-bin.000003 --start-position 168394293 --stop-position 168394293
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#240423 21:17:25 server id 1  end_log_pos 123 CRC32 0xc288674f  Start: binlog v 4, server v 5.7.36-log created 240423 21:17:25
# Warning: this binlog is either in use or was not closed properly.
BINLOG '
5bQnZg8BAAAAdwAAAHsAAAABAAQANS43LjM2LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AU9niMI=
'/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;