Bug #96142 Inconsistent error on slave for Update event on table with non-exists partition
Submitted: 9 Jul 2019 13:24 Modified: 10 Jul 2019 8:45
Reporter: lalit Choudhary Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S3 (Non-critical)
Version:5.6,5.7, 5.6.44, 5.7.26 OS:Any
Assigned to: CPU Architecture:Any

[9 Jul 2019 13:24] lalit Choudhary
Description:

Slave has an inconsistent error message on slave for Update_rows event on the table with non-exists partition as compare to table without partitioning.

Last_SQL_Error: Could not execute Update_rows event on table test.fooPar; Got error 1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.000002, end_log_pos 2630

How to repeat:
Test:
--------------------------
Table without partitioning
----------------------------
updating row on the master which is missing on the slave will result in the following error,

Last_Error: Could not execute Update_rows event on table test.foo; Can't find record in 'foo', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000002, end_log_pos 19646907
 
-------------------------
Table with partitioning.
-------------------------
updating row on the master which is missing on the slave will result in the following error,

master [localhost] {msandbox} (test) > create table fooPar (c1 int not null,c2 int not null,c3 char(100), primary key (c1,c2)) ENGINE=InnoDB DEFAULT CHARSET=utf8 /*!50100 PARTITION BY LIST (c2) (PARTITION P2 VALUES IN (2) ENGINE = InnoDB,  PARTITION P3 VALUES IN (3) ENGINE = InnoDB,  PARTITION P4 VALUES IN (4) ENGINE = InnoDB) */; 
Query OK, 0 rows affected (0.08 sec)

master [localhost] {msandbox} (test) > insert into fooPar values(1,2,'test1');     Query OK, 1 row affected (0.01 sec)

master [localhost] {msandbox} (test) > insert into fooPar values(2,3,'test2');     Query OK, 1 row affected (0.01 sec)

master [localhost] {msandbox} (test) > insert into fooPar values(3,4,'test2');     Query OK, 1 row affected (0.01 sec)

master [localhost] {msandbox} (test) > SELECT * FROM fooPar PARTITION (p4);       
+----+----+-------+
| c1 | c2 | c3    |
+----+----+-------+
|  3 |  4 | test2 |
+----+----+-------+
1 row in set (0.00 sec)

slave1 [localhost] {msandbox} (test) > SELECT * FROM fooPar PARTITION (p4);
+----+----+-------+
| c1 | c2 | c3    |
+----+----+-------+
|  3 |  4 | test2 |
+----+----+-------+
1 row in set (0.00 sec)

slave1 [localhost] {msandbox} (test) > alter table fooPar drop partition p4;
Query OK, 0 rows affected (0.07 sec)
Records: 0  Duplicates: 0  Warnings: 0

slave1 [localhost] {msandbox} (test) > SELECT * FROM fooPar PARTITION (p4);
ERROR 1735 (HY000): Unknown partition 'p4' in table 'fooPar'

master [localhost] {msandbox} (test) > update fooPar set c3='lalit' where c1=3 and c2=4;
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

master [localhost] {msandbox} (test) > SELECT * FROM fooPar PARTITION (p4);        
+----+----+-------+
| c1 | c2 | c3    |
+----+----+-------+
|  3 |  4 | lalit |
+----+----+-------+
1 row in set (0.00 sec)

my.cnf

binlog_checksum=CRC32
binlog_format=ROW
binlog_row_image=FULL
 

slave1 [localhost] {msandbox} (test) > show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 127.0.0.1
                  Master_User: rsandbox
                  Master_Port: 25107
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000002
          Read_Master_Log_Pos: 2661
               Relay_Log_File: mysql-relay.000005
                Relay_Log_Pos: 2600
        Relay_Master_Log_File: mysql-bin.000002
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
       
                   Last_Errno: 1030
                   Last_Error: Could not execute Update_rows event on table test.fooPar; Got error 1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.000002, end_log_pos 2630
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 2437
              Relay_Log_Space: 3156
              Until_Condition: None
      
               Master_SSL_Key: 
        Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 1030
               Last_SQL_Error: Could not execute Update_rows event on table test.fooPar; Got error 1 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.000002, end_log_pos 2630
  Replicate_Ignore_Server_Ids: 
             Master_Server_Id: 1
                  Master_UUID: 00025107-1111-1111-1111-111111111111
             Master_Info_File: /home/lalit/sandboxes/rsandbox_mysql-5_6_42/node1/data/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: 190709 18:21:57
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 
            Executed_Gtid_Set: 
                Auto_Position: 0
1 row in set (0.00 sec)

Suggested fix:
It should clear and consistent error message as we for missing update_event on a table without partitioning.
[9 Jul 2019 13:38] lalit Choudhary
The issue only reproduciable with binlog_format=ROW
[9 Jul 2019 14:06] lalit Choudhary
Also, reproduciable with mysql 5.7

Last_SQL_Error: Could not execute Update_rows event on table test.fooPar; Got error 122 from storage engine, Error_code: 1030; handler error No Error!; the event's master log mysql-bin.000001, end_log_pos 5751
[10 Jul 2019 8:45] MySQL Verification Team
Hello Lalit,

Thank you for the report and test case.
Verified as described.

regards,
Umesh