[MDEV-20812] Unexpected ER_ROW_IS_REFERENCED_2 or server crash in row_ins_foreign_report_err upon DELETE from versioned table with FK Created: 2019-10-11  Updated: 2022-12-15  Resolved: 2019-10-15

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Versioned Tables
Affects Version/s: 10.3, 10.4
Fix Version/s: 10.3.19, 10.4.9

Type: Bug Priority: Blocker
Reporter: Elena Stepanova Assignee: Aleksey Midenkov
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Problem/Incident
is caused by MDEV-16210 FK constraints on versioned tables us... Closed
Relates
relates to MDEV-30238 LOAD DATA REPLACE into ucs2-encoded F... Open

 Description   

First, non-crashing test case, as it is much more important than the crashing one (normal operation fails, without switching off FOREIGN_KEY_CHECKS):

--source include/have_innodb.inc
 
CREATE TABLE t1 (a INT, KEY(a)) ENGINE=InnoDB;
INSERT INTO t1 VALUES (1);
 
CREATE TABLE t2 (b INT, FOREIGN KEY (b) REFERENCES t1(a)) ENGINE=InnoDB WITH SYSTEM VERSIONING;
INSERT INTO t2 VALUES (1),(1);
 
DELETE FROM t2;
 
# Cleanup
DROP TABLE t2, t1;

DELETE unexpectedly fails:

10.3 4cdb72f2

DELETE FROM t2;
bug.fk1 'innodb'                         [ fail ]
        Test ended at 2019-10-12 01:25:45
 
CURRENT_TEST: bug.fk1
mysqltest: At line 9: query 'DELETE FROM t2' failed: 1451: Cannot delete or update a parent row: a foreign key constraint fails (`test`.`t2`, CONSTRAINT `t2_ibfk_1` FOREIGN KEY (`b`) REFERENCES `t1` (`a`))

The crashing case is basically the same, but it uses a non-existing table for the FK reference:

--source include/have_innodb.inc
 
SET FOREIGN_KEY_CHECKS= 0;
CREATE TABLE t2 (b INT, FOREIGN KEY (b) REFERENCES t1(a)) ENGINE=InnoDB WITH SYSTEM VERSIONING;
INSERT INTO t2 VALUES (1),(1);
 
SET FOREIGN_KEY_CHECKS= 1;
DELETE FROM t2;
 
# Cleanup
DROP TABLE t2;

10.3 4cdb72f2

#3  <signal handler called>
#4  0x000055fb6ddba7b8 in id_name_t::operator() (this=0x10) at /data/src/10.3/storage/innobase/include/dict0mem.h:525
#5  0x000055fb6df03342 in row_ins_foreign_report_err (errstr=0x55fb6e6d6b43 "Trying to delete or update", thr=0x7f478c06e150, foreign=0x7f478c0a5ee8, rec=0x7f47da8c008e "\200", entry=0x7f478c06f398) at /data/src/10.3/storage/innobase/row/row0ins.cc:823
#6  0x000055fb6df060db in row_ins_check_foreign_constraint (check_ref=0, foreign=0x7f478c0a5ee8, table=0x7f478c00ca08, entry=0x7f478c06f398, thr=0x7f478c06e150) at /data/src/10.3/storage/innobase/row/row0ins.cc:1894
#7  0x000055fb6df06648 in row_ins_check_foreign_constraints (table=0x7f478c00ca08, index=0x7f478c0a4b98, pk=false, entry=0x7f478c06f398, thr=0x7f478c06e150, check_ref=false) at /data/src/10.3/storage/innobase/row/row0ins.cc:2042
#8  0x000055fb6df0a3b4 in row_ins_sec_index_entry (index=0x7f478c0a4b98, entry=0x7f478c06f398, thr=0x7f478c06e150, check_ref=false) at /data/src/10.3/storage/innobase/row/row0ins.cc:3288
#9  0x000055fb6df9e8f5 in row_upd_sec_index_entry (node=0x7f478c06de18, thr=0x7f478c06e150) at /data/src/10.3/storage/innobase/row/row0upd.cc:2532
#10 0x000055fb6df9eb54 in row_upd_sec_step (node=0x7f478c06de18, thr=0x7f478c06e150) at /data/src/10.3/storage/innobase/row/row0upd.cc:2560
#11 0x000055fb6dfa18f3 in row_upd (node=0x7f478c06de18, thr=0x7f478c06e150) at /data/src/10.3/storage/innobase/row/row0upd.cc:3327
#12 0x000055fb6dfa1d40 in row_upd_step (thr=0x7f478c06e150) at /data/src/10.3/storage/innobase/row/row0upd.cc:3442
#13 0x000055fb6df33506 in row_update_for_mysql (prebuilt=0x7f478c06d2e8) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1888
#14 0x000055fb6dd9f49f in ha_innobase::update_row (this=0x7f478c06cb38, old_row=0x7f478c0082b8 "\375\001", new_row=0x7f478c0082a0 "\375\001") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8850
#15 0x000055fb6db7e80e in handler::ha_update_row (this=0x7f478c06cb38, old_data=0x7f478c0082b8 "\375\001", new_data=0x7f478c0082a0 "\375\001") at /data/src/10.3/sql/handler.cc:6478
#16 0x000055fb6dd25c47 in TABLE::delete_row (this=0x7f478c06bef0) at /data/src/10.3/sql/sql_delete.cc:257
#17 0x000055fb6dd22e4a in mysql_delete (thd=0x7f478c000b00, table_list=0x7f478c0128e0, conds=0x0, order_list=0x7f478c0053c8, limit=18446744073709551615, options=0, result=0x0) at /data/src/10.3/sql/sql_delete.cc:750
#18 0x000055fb6d859255 in mysql_execute_command (thd=0x7f478c000b00) at /data/src/10.3/sql/sql_parse.cc:4653
#19 0x000055fb6d863d81 in mysql_parse (thd=0x7f478c000b00, rawbuf=0x7f478c012818 "DELETE FROM t2", length=14, parser_state=0x7f47da12f5e0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7829
#20 0x000055fb6d8509bb in dispatch_command (command=COM_QUERY, thd=0x7f478c000b00, packet=0x7f478c15fe41 "DELETE FROM t2", packet_length=14, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1855
#21 0x000055fb6d84f303 in do_command (thd=0x7f478c000b00) at /data/src/10.3/sql/sql_parse.cc:1400
#22 0x000055fb6d9c6014 in do_handle_one_connection (connect=0x55fb71ab63e0) at /data/src/10.3/sql/sql_connect.cc:1403
#23 0x000055fb6d9c5d76 in handle_one_connection (arg=0x55fb71ab63e0) at /data/src/10.3/sql/sql_connect.cc:1308
#24 0x000055fb6e3732ec in pfs_spawn_thread (arg=0x55fb719fb9d0) at /data/src/10.3/storage/perfschema/pfs.cc:1862
#25 0x00007f47e692b4a4 in start_thread (arg=0x7f47da130700) at pthread_create.c:456
#26 0x00007f47e4e72d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

All of debug, non-debug and ASAN builds crash the same way.

The problem was introduced in 10.3 by this commit:

commit 75ba5c815d0272b35a28225d495a4a03fe63d29f
Author: Aleksey Midenkov
Date:   Wed May 30 13:19:03 2018 +0300
 
    MDEV-16210 FK constraints on versioned tables use historical rows, which may cause constraint violation



 Comments   
Comment by Elena Stepanova [ 2019-10-18 ]

For a record, here is another kind of failure which was apparently fixed by the same patch. The test case is not prettified and 10.4-specific due to a long unique on blob.

--source include/have_innodb.inc
 
CREATE TABLE ts9 ( `c1` CHAR(163), `from` DATETIME NULL, `to` DATETIME NULL DEFAULT '2000-01-01 00:00:00', `c4` BIGINT NULL DEFAULT 0, `c5` TIME NOT NULL DEFAULT '00:00:00', `c6` TIME, `c7` TEXT ) ENGINE=InnoDB WITH SYSTEM VERSIONING;
SET system_versioning_alter_history=KEEP /* QNO 139 CON_ID 16 */;
ALTER IGNORE TABLE `ts9` /*!100301 WAIT 6 */ ADD COLUMN IF NOT EXISTS ( s VARCHAR(11220) NULL ), ADD UNIQUE(c7);
INSERT IGNORE INTO `ts9` () VALUES (),(),(),() /* QNO 583 CON_ID 17 */;
SET FOREIGN_KEY_CHECKS = OFF /* QNO 463 CON_ID 17 */;
ALTER IGNORE TABLE `ts9` /*!100301 WAIT 5 */ ADD FOREIGN KEY ( `to` ) REFERENCES `t9` (`from`) ON DELETE CASCADE, LOCK=SHARED /* QNO 636 CON_ID 17 */;
SET FOREIGN_KEY_CHECKS = ON;
DELETE FROM `ts9` ORDER BY `c5`  /* QNO 999 CON_ID 16 */;

10.4 5b6b1663

mysqld: /data/src/10.4-bug/storage/innobase/handler/ha_innodb.cc:20602: dfield_t* innobase_get_computed_value(dtuple_t*, const dict_v_col_t*, const dict_index_t*, mem_heap_t**, mem_heap_t*, const dict_field_t*, THD*, TABLE*, byte*, const dict_table_t*, upd_t*, dict_foreign_t*): Assertion `mysql_table' failed.
191019  2:02:49 [ERROR] mysqld got signal 6 ;
 
#6  0x00007f14128bee67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x5647900239f1 "mysql_table", file=file@entry=0x564790016d00 "/data/src/10.4-bug/storage/innobase/handler/ha_innodb.cc", line=line@entry=20602, function=function@entry=0x564790028340 <innobase_get_computed_value(dtuple_t*, dict_v_col_t const*, dict_index_t const*, mem_block_info_t**, mem_block_info_t*, dict_field_t const*, THD*, TABLE*, unsigned char*, dict_table_t const*, upd_t*, dict_foreign_t*)::__PRETTY_FUNCTION__> "dfield_t* innobase_get_computed_value(dtuple_t*, const dict_v_col_t*, const dict_index_t*, mem_heap_t**, mem_heap_t*, const dict_field_t*, THD*, TABLE*, byte*, const dict_table_t*, upd_t*, dict_foreig"...) at assert.c:92
#7  0x00007f14128bef12 in __GI___assert_fail (assertion=0x5647900239f1 "mysql_table", file=0x564790016d00 "/data/src/10.4-bug/storage/innobase/handler/ha_innodb.cc", line=20602, function=0x564790028340 <innobase_get_computed_value(dtuple_t*, dict_v_col_t const*, dict_index_t const*, mem_block_info_t**, mem_block_info_t*, dict_field_t const*, THD*, TABLE*, unsigned char*, dict_table_t const*, upd_t*, dict_foreign_t*)::__PRETTY_FUNCTION__> "dfield_t* innobase_get_computed_value(dtuple_t*, const dict_v_col_t*, const dict_index_t*, mem_heap_t**, mem_heap_t*, const dict_field_t*, THD*, TABLE*, byte*, const dict_table_t*, upd_t*, dict_foreig"...) at assert.c:101
#8  0x000056478f6f594d in innobase_get_computed_value (row=0x7f13b81535e8, col=0x7f13b81c1b28, index=0x7f13b81c4508, local_heap=0x7f140c48af08, heap=0x7f13b819e550, ifield=0x0, thd=0x7f13b8000b00, mysql_table=0x0, mysql_rec=0x0, old_table=0x0, parent_update=0x0, foreign=0x0) at /data/src/10.4-bug/storage/innobase/handler/ha_innodb.cc:20602
#9  0x000056478f8e0820 in row_upd_store_v_row (node=0x7f13b81c2fc8, update=0x0, thd=0x7f13b8000b00, mysql_table=0x0) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:2178
#10 0x000056478f8e0acb in row_upd_store_row (node=0x7f13b81c2fc8, thd=0x7f13b8000b00, mysql_table=0x0) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:2242
#11 0x000056478f8e4623 in row_upd_clust_step (node=0x7f13b81c2fc8, thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:3194
#12 0x000056478f8e4a94 in row_upd (node=0x7f13b81c2fc8, thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:3289
#13 0x000056478f8e505a in row_upd_step (thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:3433
#14 0x000056478f881a75 in row_update_cascade_for_mysql (thr=0x7f13b8159090, node=0x7f13b81c2fc8, table=0x7f13b81c1568) at /data/src/10.4-bug/storage/innobase/row/row0mysql.cc:2264
#15 0x000056478f8535f5 in row_ins_foreign_check_on_constraint (thr=0x7f13b8159090, foreign=0x7f13b81c62c8, pcur=0x7f140c48c040, entry=0x7f13b80451e8, mtr=0x7f140c48c4a0) at /data/src/10.4-bug/storage/innobase/row/row0ins.cc:1441
#16 0x000056478f854692 in row_ins_check_foreign_constraint (check_ref=0, foreign=0x7f13b81c62c8, table=0x7f13b81c1568, entry=0x7f13b80451e8, thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0ins.cc:1850
#17 0x000056478f854c6d in row_ins_check_foreign_constraints (table=0x7f13b81c1568, index=0x7f13b81c6568, pk=false, entry=0x7f13b80451e8, thr=0x7f13b8159090, check_ref=false) at /data/src/10.4-bug/storage/innobase/row/row0ins.cc:2027
#18 0x000056478f858c87 in row_ins_sec_index_entry (index=0x7f13b81c6568, entry=0x7f13b80451e8, thr=0x7f13b8159090, check_ref=false) at /data/src/10.4-bug/storage/innobase/row/row0ins.cc:3289
#19 0x000056478f8e19c5 in row_upd_sec_index_entry (node=0x7f13b8158bd8, thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:2513
#20 0x000056478f8e1c16 in row_upd_sec_step (node=0x7f13b8158bd8, thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:2540
#21 0x000056478f8e4c14 in row_upd (node=0x7f13b8158bd8, thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:3318
#22 0x000056478f8e505a in row_upd_step (thr=0x7f13b8159090) at /data/src/10.4-bug/storage/innobase/row/row0upd.cc:3433
#23 0x000056478f880b4c in row_update_for_mysql (prebuilt=0x7f13b8158258) at /data/src/10.4-bug/storage/innobase/row/row0mysql.cc:1889
#24 0x000056478f6dfde8 in ha_innobase::update_row (this=0x7f13b81a01d8, old_row=0x7f13b804bde0 "\363", ' ' <repeats 163 times>, "\200", new_row=0x7f13b8049128 "\363", ' ' <repeats 163 times>, "\200") at /data/src/10.4-bug/storage/innobase/handler/ha_innodb.cc:8841
#25 0x000056478f4a1e2c in handler::ha_update_row (this=0x7f13b81a01d8, old_data=0x7f13b804bde0 "\363", ' ' <repeats 163 times>, "\200", new_data=0x7f13b8049128 "\363", ' ' <repeats 163 times>, "\200") at /data/src/10.4-bug/sql/handler.cc:6719
#26 0x000056478f65c8cb in TABLE::delete_row (this=0x7f13b81bf4c0) at /data/src/10.4-bug/sql/sql_delete.cc:301
#27 0x000056478f65974a in mysql_delete (thd=0x7f13b8000b00, table_list=0x7f13b8013258, conds=0x0, order_list=0x7f13b80054b0, limit=18446744073709551615, options=0, result=0x0) at /data/src/10.4-bug/sql/sql_delete.cc:834
#28 0x000056478f136b13 in mysql_execute_command (thd=0x7f13b8000b00) at /data/src/10.4-bug/sql/sql_parse.cc:4723
#29 0x000056478f142351 in mysql_parse (thd=0x7f13b8000b00, rawbuf=0x7f13b8013128 "DELETE FROM `ts9` ORDER BY `c5`  /* QNO 999 CON_ID 16 */", length=56, parser_state=0x7f140c48f170, is_com_multi=false, is_next_command=false) at /data/src/10.4-bug/sql/sql_parse.cc:7912
#30 0x000056478f12d5e4 in dispatch_command (command=COM_QUERY, thd=0x7f13b8000b00, packet=0x7f13b8137a21 "DELETE FROM `ts9` ORDER BY `c5`  /* QNO 999 CON_ID 16 */", packet_length=56, is_com_multi=false, is_next_command=false) at /data/src/10.4-bug/sql/sql_parse.cc:1841
#31 0x000056478f12bc71 in do_command (thd=0x7f13b8000b00) at /data/src/10.4-bug/sql/sql_parse.cc:1359
#32 0x000056478f2b36a3 in do_handle_one_connection (connect=0x564791a10c10) at /data/src/10.4-bug/sql/sql_connect.cc:1412
#33 0x000056478f2b33f2 in handle_one_connection (arg=0x564791a10c10) at /data/src/10.4-bug/sql/sql_connect.cc:1316
#34 0x000056478fcb61b3 in pfs_spawn_thread (arg=0x564791935860) at /data/src/10.4-bug/storage/perfschema/pfs.cc:1862
#35 0x00007f14144344a4 in start_thread (arg=0x7f140c490700) at pthread_create.c:456
#36 0x00007f141297bd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Generated at Thu Feb 08 09:02:21 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.