[MDEV-21555] Assertion secondary index is out of sync on delete from versioned table Created: 2020-01-22  Updated: 2021-08-18  Resolved: 2021-08-18

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Versioned Tables, Virtual Columns
Affects Version/s: 10.3, 10.4, 10.5
Fix Version/s: 10.3.32, 10.4.22, 10.5.13, 10.6.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Aleksey Midenkov
Resolution: Fixed Votes: 0
Labels: None


 Description   

Assertion `!"secondary index is out of sync"' failed in dict_index_t::vers_history_row

--source include/have_innodb.inc
 
CREATE TABLE t1 (a INT, b INT AS (a*2) VIRTUAL, KEY(a)) ENGINE=InnoDB WITH SYSTEM VERSIONING;
SET FOREIGN_KEY_CHECKS = OFF;
INSERT IGNORE INTO t1 (a) VALUES (1),(2),(3),(4);
ALTER TABLE t1 ADD FOREIGN KEY (b) REFERENCES t1 (a), ALGORITHM=COPY;
UPDATE t1 SET a = NULL ORDER BY a LIMIT 2;
DELETE FROM t1 ORDER BY a, b LIMIT 2;
SET FOREIGN_KEY_CHECKS = ON;
DELETE HISTORY FROM t1;
DELETE FROM t1;
 
# Cleanup
DROP TABLE t1;

10.3 ade89fc8

mysqld: /data/src/10.3/storage/innobase/dict/dict0mem.cc:1504: bool dict_index_t::vers_history_row(const rec_t*, bool&): Assertion `!"secondary index is out of sync"' failed.
200122 18:58:46 [ERROR] mysqld got signal 6 ;
 
#6  0x00007fccad32de67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x55fa615f39a0 "!\"secondary index is out of sync\"", file=file@entry=0x55fa615f2fb8 "/data/src/10.3/storage/innobase/dict/dict0mem.cc", line=line@entry=1504, function=function@entry=0x55fa615f4ea0 <dict_index_t::vers_history_row(unsigned char const*, bool&)::__PRETTY_FUNCTION__> "bool dict_index_t::vers_history_row(const rec_t*, bool&)") at assert.c:92
#7  0x00007fccad32df12 in __GI___assert_fail (assertion=0x55fa615f39a0 "!\"secondary index is out of sync\"", file=0x55fa615f2fb8 "/data/src/10.3/storage/innobase/dict/dict0mem.cc", line=1504, function=0x55fa615f4ea0 <dict_index_t::vers_history_row(unsigned char const*, bool&)::__PRETTY_FUNCTION__> "bool dict_index_t::vers_history_row(const rec_t*, bool&)") at assert.c:101
#8  0x000055fa60f8303f in dict_index_t::vers_history_row (this=0x7fcc5c094418, rec=0x7fcca2e9808e "\200", history_row=@0x7fcca269faea: false) at /data/src/10.3/storage/innobase/dict/dict0mem.cc:1504
#9  0x000055fa60d6224a in row_ins_check_foreign_constraint (check_ref=0, foreign=0x7fcc5c0921b8, table=0x7fcc5c08fa78, entry=0x7fcc5c03f018, thr=0x7fcc5c074ba0) at /data/src/10.3/storage/innobase/row/row0ins.cc:1776
#10 0x000055fa60df533c in row_upd_check_references_constraints (node=0x7fcc5c074838, pcur=0x7fcca26a0580, table=0x7fcc5c08fa78, index=0x7fcc5c093aa8, offsets=0x7fcc5c03ebf0, thr=0x7fcc5c074ba0, mtr=0x7fcca26a0c80) at /data/src/10.3/storage/innobase/row/row0upd.cc:295
#11 0x000055fa60dfb434 in row_upd_sec_index_entry (node=0x7fcc5c074838, thr=0x7fcc5c074ba0) at /data/src/10.3/storage/innobase/row/row0upd.cc:2517
#12 0x000055fa60dfb7a3 in row_upd_sec_step (node=0x7fcc5c074838, thr=0x7fcc5c074ba0) at /data/src/10.3/storage/innobase/row/row0upd.cc:2566
#13 0x000055fa60dfe565 in row_upd (node=0x7fcc5c074838, thr=0x7fcc5c074ba0) at /data/src/10.3/storage/innobase/row/row0upd.cc:3336
#14 0x000055fa60dfe9b2 in row_upd_step (thr=0x7fcc5c074ba0) at /data/src/10.3/storage/innobase/row/row0upd.cc:3451
#15 0x000055fa60d8fbb7 in row_update_for_mysql (prebuilt=0x7fcc5c074018) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1888
#16 0x000055fa60bf8d2b in ha_innobase::update_row (this=0x7fcc5c0724e8, old_row=0x7fcc5c0720a8 "\371\004", new_row=0x7fcc5c072090 "\371\004") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8838
#17 0x000055fa609d7cd8 in handler::ha_update_row (this=0x7fcc5c0724e8, old_data=0x7fcc5c0720a8 "\371\004", new_data=0x7fcc5c072090 "\371\004") at /data/src/10.3/sql/handler.cc:6479
#18 0x000055fa60b7ec95 in TABLE::delete_row (this=0x7fcc5c0a4da0) at /data/src/10.3/sql/sql_delete.cc:249
#19 0x000055fa60b7bd59 in mysql_delete (thd=0x7fcc5c000af0, table_list=0x7fcc5c0128e0, conds=0x7fcc5c013bc0, order_list=0x7fcc5c0053b8, limit=18446744073709551614, options=0, result=0x0) at /data/src/10.3/sql/sql_delete.cc:720
#20 0x000055fa606b1066 in mysql_execute_command (thd=0x7fcc5c000af0) at /data/src/10.3/sql/sql_parse.cc:4658
#21 0x000055fa606bbb91 in mysql_parse (thd=0x7fcc5c000af0, rawbuf=0x7fcc5c012818 "DELETE FROM t1", length=14, parser_state=0x7fcca26a25e0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7818
#22 0x000055fa606a8705 in dispatch_command (command=COM_QUERY, thd=0x7fcc5c000af0, packet=0x7fcc5c165951 "DELETE FROM t1", packet_length=14, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1856
#23 0x000055fa606a704d in do_command (thd=0x7fcc5c000af0) at /data/src/10.3/sql/sql_parse.cc:1401
#24 0x000055fa6081e9bc in do_handle_one_connection (connect=0x55fa63546850) at /data/src/10.3/sql/sql_connect.cc:1403
#25 0x000055fa6081e71e in handle_one_connection (arg=0x55fa63546850) at /data/src/10.3/sql/sql_connect.cc:1308
#26 0x000055fa611cf6ee in pfs_spawn_thread (arg=0x55fa634eacb0) at /data/src/10.3/storage/perfschema/pfs.cc:1869
#27 0x00007fccaf2b64a4 in start_thread (arg=0x7fcca26a3700) at pthread_create.c:456
#28 0x00007fccad3ead0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Reproducible with 10.3-10.5.

Non-debug version doesn't crash, but produces an error in the error log:

10.3 ade89fc8 non-debug

2020-01-22 19:00:01 9 [ERROR] InnoDB: foreign constraints: secondary index is out of sync



 Comments   
Comment by Elena Stepanova [ 2020-04-14 ]

The assertion mutated a bit in 10.5:

10.5 91e79dff

mariadbd: /data/src/10.5/storage/innobase/dict/dict0mem.cc:1338: bool dict_index_t::vers_history_row(const rec_t*, bool&): Assertion `"secondary index is out of sync" == 0' failed.
200414 21:49:29 [ERROR] mysqld got signal 6 ;
 
c/10.5/storage/innobase/dict/dict0mem.cc", line=1338, function=0x55d8c8d74b40 <dict_index_t::vers_history_row(unsigned char const*, bool&)::__PRETTY_FUNCTION__> "bool dict_index_t::vers_history_row(const rec_t*, bool&)") at assert.c:101
#8  0x000055d8c7a141bd in dict_index_t::vers_history_row (this=0x6190000e7f20, rec=0x7f669536807e "\200", history_row=@0x7f668ff4e720: false) at /data/src/10.5/storage/innobase/dict/dict0mem.cc:1338
#9  0x000055d8c7637232 in row_ins_check_foreign_constraint (check_ref=1, foreign=0x616000060a20, table=0x6190000e5720, entry=0x61b000070f20, thr=0x6210000f1e98) at /data/src/10.5/storage/innobase/row/row0ins.cc:1746
#10 0x000055d8c76382e9 in row_ins_check_foreign_constraints (table=0x6190000e5720, index=0x6190000e9d20, pk=false, entry=0x61b000070f20, thr=0x6210000f1e98) at /data/src/10.5/storage/innobase/row/row0ins.cc:1992
#11 0x000055d8c763eaa2 in row_ins_sec_index_entry (index=0x6190000e9d20, entry=0x61b000070f20, thr=0x6210000f1e98, check_foreign=true) at /data/src/10.5/storage/innobase/row/row0ins.cc:3254
#12 0x000055d8c763f060 in row_ins_index_entry (index=0x6190000e9d20, entry=0x61b000070f20, thr=0x6210000f1e98) at /data/src/10.5/storage/innobase/row/row0ins.cc:3330
#13 0x000055d8c764014c in row_ins_index_entry_step (node=0x6210000f1bc0, thr=0x6210000f1e98) at /data/src/10.5/storage/innobase/row/row0ins.cc:3497
#14 0x000055d8c7640b61 in row_ins (node=0x6210000f1bc0, thr=0x6210000f1e98) at /data/src/10.5/storage/innobase/row/row0ins.cc:3634
#15 0x000055d8c7641bc0 in row_ins_step (thr=0x6210000f1e98) at /data/src/10.5/storage/innobase/row/row0ins.cc:3773
#16 0x000055d8c768b4ed in row_insert_for_mysql (mysql_rec=0x6190000f1040 "\341", prebuilt=0x6210000f15a0, ins_mode=ROW_INS_NORMAL) at /data/src/10.5/storage/innobase/row/row0mysql.cc:1462
#17 0x000055d8c7309bc3 in ha_innobase::write_row (this=0x61d000265328, record=0x6190000f1040 "\341") at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:7771
#18 0x000055d8c685d899 in handler::ha_write_row (this=0x61d000265328, buf=0x6190000f1040 "\341") at /data/src/10.5/sql/handler.cc:6946
#19 0x000055d8c5fb350f in write_record (thd=0x62b0000bd288, table=0x620000050108, info=0x7f668ff50710, sink=0x0) at /data/src/10.5/sql/sql_insert.cc:2091
#20 0x000055d8c5fab325 in mysql_insert (thd=0x62b0000bd288, table_list=0x62b0000c4408, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=true, result=0x0) at /data/src/10.5/sql/sql_insert.cc:1088
#21 0x000055d8c606e7ab in mysql_execute_command (thd=0x62b0000bd288) at /data/src/10.5/sql/sql_parse.cc:4515
#22 0x000055d8c6087173 in mysql_parse (thd=0x62b0000bd288, rawbuf=0x62b0000c42a8 "INSERT IGNORE INTO table_virtual (field1) VALUES (0),(5)", length=56, parser_state=0x7f668ff51a50, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7953
#23 0x000055d8c605cf63 in dispatch_command (command=COM_QUERY, thd=0x62b0000bd288, packet=0x6290002bc289 "INSERT IGNORE INTO table_virtual (field1) VALUES (0),(5)", packet_length=56, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1839
#24 0x000055d8c6059998 in do_command (thd=0x62b0000bd288) at /data/src/10.5/sql/sql_parse.cc:1358
#25 0x000055d8c6478eb1 in do_handle_one_connection (connect=0x611000030908, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1422
#26 0x000055d8c647874c in handle_one_connection (arg=0x611000030908) at /data/src/10.5/sql/sql_connect.cc:1319
#27 0x000055d8c7117a06 in pfs_spawn_thread (arg=0x61600000fa08) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#28 0x00007f669f0f0fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#29 0x00007f669e93f4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Alice Sherepa [ 2021-06-10 ]

also with row_upd_clust_rec_by_insert/row_upd_clust_step

2021-06-10 15:23:58 12 [ERROR] InnoDB: foreign constraints: secondary index is out of sync
mysqld: /10.6/storage/innobase/dict/dict0mem.cc:1375: bool dict_index_t::vers_history_row(const rec_t*, bool&): Assertion `"secondary index is out of sync" == 0' failed.
210610 15:23:58 [ERROR] mysqld got signal 6 ;
 
:0(__GI___assert_fail)[0x7fdae3d65f36]
dict/dict0mem.cc:1376(dict_index_t::vers_history_row(unsigned char const*, bool&))[0x55700b4bd8ef]
row/row0ins.cc:1676(row_ins_check_foreign_constraint(unsigned long, dict_foreign_t*, dict_table_t*, dtuple_t*, que_thr_t*))[0x55700b146e4f]
row/row0upd.cc:293(row_upd_check_references_constraints(upd_node_t*, btr_pcur_t*, dict_table_t*, dict_index_t*, unsigned short*, que_thr_t*, mtr_t*))[0x55700b241006]
row/row0upd.cc:2483(row_upd_clust_rec_by_insert(upd_node_t*, dict_index_t*, que_thr_t*, bool, bool, mtr_t*))[0x55700b24e5d8]
row/row0upd.cc:2889(row_upd_clust_step(upd_node_t*, que_thr_t*))[0x55700b25146f]
row/row0upd.cc:2965(row_upd(upd_node_t*, que_thr_t*))[0x55700b251da4]
row/row0upd.cc:3109(row_upd_step(que_thr_t*))[0x55700b252d30]
row/row0mysql.cc:1810(row_update_for_mysql(row_prebuilt_t*))[0x55700b19e954]
handler/ha_innodb.cc:8457(ha_innobase::update_row(unsigned char const*, unsigned char const*))[0x55700adf6f94]
sql/handler.cc:7547(handler::ha_update_row(unsigned char const*, unsigned char const*))[0x55700a2f5ba1]
sql/sql_delete.cc:285(TABLE::delete_row())[0x55700a785faf]
sql/sql_delete.cc:820(mysql_delete(THD*, TABLE_LIST*, Item*, SQL_I_List<st_order>*, unsigned long long, unsigned long long, select_result*))[0x55700a77cf29]
sql/sql_parse.cc:4798(mysql_execute_command(THD*))[0x557009a8b1a2]
sql/sql_parse.cc:8016(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x557009aa14d9]
sql/sql_parse.cc:1899(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x557009a7765f]
sql/sql_parse.cc:1406(do_command(THD*, bool))[0x557009a7438c]
sql/sql_connect.cc:1410(do_handle_one_connection(CONNECT*, bool))[0x557009ed6638]
sql/sql_connect.cc:1314(handle_one_connection)[0x557009ed5f95]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x55700abec443]
nptl/pthread_create.c:478(start_thread)[0x7fdae427b609]
x86_64/clone.S:97(__GI___clone)[0x7fdae3e51293]

Comment by Aleksey Midenkov [ 2021-07-20 ]

Please review bb-10.3-midenok

Comment by Eugene Kosov (Inactive) [ 2021-07-20 ]

Looks good to me.

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