[MDEV-12004] InnoDB wrongly thinks that a column is indexed after failed ADD UNIQUE INDEX Created: 2017-02-06  Updated: 2019-04-26  Resolved: 2017-02-07

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Virtual Columns
Affects Version/s: 10.2.3
Fix Version/s: 10.2.4

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: 10.2-ga


 Description   

10.2 e51b015fc354

 
2017-02-06 23:09:55 0x7ff6d2ea7300  InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/trx/trx0rec.cc line 233
 
InnoDB: Failing assertion: n_idx > 0
 
 
 
#6  0x00007ff6d246d8e4 in ut_dbg_assertion_failed (expr=0x7ff6d29a4aca "n_idx > 0", file=0x7ff6d29a4a60 "/data/src/10.2/storage/innobase/trx/trx0rec.cc", line=233) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:59
 
#7  0x00007ff6d24432ac in trx_undo_log_v_idx (undo_page=0x7ff6c6464000 "\271\325\274\v", table=0x7ff6b6165688, pos=0, ptr=0x7ff6c6464120 "2-4a82-6\001\020", first_v_col=true) at /data/src/10.2/storage/innobase/trx/trx0rec.cc:233
 
#8  0x00007ff6d2443759 in trx_undo_report_insert_virtual (undo_page=0x7ff6c6464000 "\271\325\274\v", table=0x7ff6b6165688, row=0x7ff6b61f7f88, ptr=0x7ff6d2ea3068) at /data/src/10.2/storage/innobase/trx/trx0rec.cc:414
 
#9  0x00007ff6d2443bb8 in trx_undo_page_report_insert (undo_page=0x7ff6c6464000 "\271\325\274\v", trx=0x7ff6c6c008e8, index=0x7ff6b6165d88, clust_entry=0x7ff6b61f7f88, mtr=0x7ff6d2ea3150) at /data/src/10.2/storage/innobase/trx/trx0rec.cc:529
 
#10 0x00007ff6d2447421 in trx_undo_report_row_operation (flags=0, op_type=1, thr=0x7ff6b6189860, index=0x7ff6b6165d88, clust_entry=0x7ff6b61f7f88, update=0x0, cmpl_info=0, rec=0x0, offsets=0x0, roll_ptr=0x7ff6d2ea3710) at /data/src/10.2/storage/innobase/trx/trx0rec.cc:1992
 
#11 0x00007ff6d24a7ed1 in btr_cur_ins_lock_and_undo (flags=0, cursor=0x7ff6d2ea3a60, entry=0x7ff6b61f7f88, thr=0x7ff6b6189860, mtr=0x7ff6d2ea3e80, inherit=0x7ff6d2ea3790) at /data/src/10.2/storage/innobase/btr/btr0cur.cc:2819
 
#12 0x00007ff6d24a871c in btr_cur_optimistic_insert (flags=0, cursor=0x7ff6d2ea3a60, offsets=0x7ff6d2ea3a00, heap=0x7ff6d2ea39f8, entry=0x7ff6b61f7f88, rec=0x7ff6d2ea3a08, big_rec=0x7ff6d2ea39f0, n_ext=0, thr=0x7ff6b6189860, mtr=0x7ff6d2ea3e80) at /data/src/10.2/storage/innobase/btr/btr0cur.cc:3037
 
#13 0x00007ff6d2373cc3 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7ff6b6165d88, n_uniq=0, entry=0x7ff6b61f7f88, n_ext=0, thr=0x7ff6b6189860, dup_chk_only=false) at /data/src/10.2/storage/innobase/row/row0ins.cc:2617
 
#14 0x00007ff6d23756ba in row_ins_clust_index_entry (index=0x7ff6b6165d88, entry=0x7ff6b61f7f88, thr=0x7ff6b6189860, n_ext=0, dup_chk_only=false) at /data/src/10.2/storage/innobase/row/row0ins.cc:3169
 
#15 0x00007ff6d2375a88 in row_ins_index_entry (index=0x7ff6b6165d88, entry=0x7ff6b61f7f88, thr=0x7ff6b6189860) at /data/src/10.2/storage/innobase/row/row0ins.cc:3276
 
#16 0x00007ff6d2375fc4 in row_ins_index_entry_step (node=0x7ff6b61895e8, thr=0x7ff6b6189860) at /data/src/10.2/storage/innobase/row/row0ins.cc:3426
 
#17 0x00007ff6d237637d in row_ins (node=0x7ff6b61895e8, thr=0x7ff6b6189860) at /data/src/10.2/storage/innobase/row/row0ins.cc:3568
 
#18 0x00007ff6d2376995 in row_ins_step (thr=0x7ff6b6189860) at /data/src/10.2/storage/innobase/row/row0ins.cc:3752
 
#19 0x00007ff6d2393d28 in row_insert_for_mysql (mysql_rec=0x7ff6b601c188 "\375\002", prebuilt=0x7ff6b6189088) at /data/src/10.2/storage/innobase/row/row0mysql.cc:1510
 
#20 0x00007ff6d224cbbb in ha_innobase::write_row (this=0x7ff6b60b7888, record=0x7ff6b601c188 "\375\002") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:8758
 
#21 0x00007ff6d200d773 in handler::ha_write_row (this=0x7ff6b60b7888, buf=0x7ff6b601c188 "\375\002") at /data/src/10.2/sql/handler.cc:5960
 
#22 0x00007ff6d1d7432d in write_record (thd=0x7ff6b6016070, table=0x7ff6b60d7870, info=0x7ff6d2ea5090) at /data/src/10.2/sql/sql_insert.cc:1886
 
#23 0x00007ff6d1d71d45 in mysql_insert (thd=0x7ff6b6016070, table_list=0x7ff6b6064188, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=true) at /data/src/10.2/sql/sql_insert.cc:998
 
#24 0x00007ff6d1d98f70 in mysql_execute_command (thd=0x7ff6b6016070) at /data/src/10.2/sql/sql_parse.cc:4372
 
#25 0x00007ff6d1da3fcc in mysql_parse (thd=0x7ff6b6016070, rawbuf=0x7ff6b6064088 "INSERT IGNORE INTO t1 (f) VALUES (2),(2)", length=40, parser_state=0x7ff6d2ea5dd0, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7842
 
#26 0x00007ff6d1d920d7 in dispatch_command (command=COM_QUERY, thd=0x7ff6b6016070, packet=0x7ff6b6058071 "INSERT IGNORE INTO t1 (f) VALUES (2),(2)", packet_length=40, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1800
 
#27 0x00007ff6d1d90acf in do_command (thd=0x7ff6b6016070) at /data/src/10.2/sql/sql_parse.cc:1360
 
#28 0x00007ff6d1ed950c in do_handle_one_connection (connect=0x7ff6ce871f70) at /data/src/10.2/sql/sql_connect.cc:1354
 
#29 0x00007ff6d1ed9299 in handle_one_connection (arg=0x7ff6ce871f70) at /data/src/10.2/sql/sql_connect.cc:1260
 
#30 0x00007ff6d221cd00 in pfs_spawn_thread (arg=0x7ff6c5fbf870) at /data/src/10.2/storage/perfschema/pfs.cc:1862
 
#31 0x00007ff6d13c00a4 in start_thread (arg=0x7ff6d2ea7300) at pthread_create.c:309
 
#32 0x00007ff6cf36d87d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Non-deterministic test case, run with --repeat=N

 
# Run with --repeat=N
 
 
 
--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (f INT, vf INT AS (f) VIRTUAL) ENGINE=InnoDB;
 
INSERT IGNORE INTO t1 (f) VALUES (1),(1);
 
 
 
--connect (con1,127.0.0.1,root,,test)
 
--send
 
ALTER TABLE t1 ADD UNIQUE KEY id(vf,f);
 
 
 
--connection default
 
SELECT f FROM t1;
 
SELECT f FROM t1;
 
TRUNCATE TABLE t1;
 
INSERT IGNORE INTO t1 (f) VALUES (2),(2);
 
 
 
# Cleanup
 
--connection con1
 
--error 0,ER_DUP_ENTRY
 
--reap
 
DROP TABLE t1;
 
--disconnect con1



 Comments   
Comment by Marko Mäkelä [ 2017-02-07 ]

The problem appears to be that the dict_v_col_t::v_indexes is inconsistent with the table definition. It should have been emptied when the ALTER TABLE operation was rolled back.

After crash recovery, the table is empty, consisting of an empty clustered index root page with PAGE_INDEX_ID 0x15. There is no secondary index. In SYS_INDEXES, the last record is (TABLE_ID=0x14,ID=0x15,DB_TRX_ID=0x509,DB_ROLL_PTR=(insert),NAME='GEN_CLUST_INDEX',N_FIELDS=0,TYPE=DICT_CLUSTERED,SPACE=4,PAGE_NO=3,MERGE_THRESHOLD=50).
There has been no attempt to insert a SYS_INDEXES record for the ADD UNIQUE KEY.

So, it seems that the ALTER TABLE must have returned ER_DUP_ENTRY, and then TRUNCATE TABLE must have emptied the table.

With a DEBUG_SYNC on inplace_after_index_build, I verified that the TRUNCATE is blocked until ha_innobase::inplace_alter_table() returns control to the SQL layer. TRUNCATE should still be blocked while ha_innobase::commit_inplace_alter_table() is executing, to roll back the failed ALTER TABLE operation. Actually it turns out that mysql_alter_table() must return before TRUNCATE TABLE can continue:

2017-02-07  9:13:14 140520488080128 [Note] InnoDB: Online DDL : End of reading clustered index of the table and create temporary files 18
 
2017-02-07  9:13:14 140520488080128 [Note] alter failed
 
2017-02-07  9:13:14 140520491856640 [Note] InnoDB: Truncate start `test`.`t1`
 
2017-02-07 09:13:14 0x7fcd7a003300  InnoDB: Assertion failure in file /mariadb/server/storage/innobase/trx/trx0rec.cc line 233

The two last Note were produced by a patch:

diff --git a/sql/sql_table.cc b/sql/sql_table.cc
 
index 2df3f4ef34a..d5bc215c7a4 100644
 
--- a/sql/sql_table.cc
 
+++ b/sql/sql_table.cc
 
@@ -9228,8 +9228,10 @@ bool mysql_alter_table(THD *thd,char *new_db, char *new_name,
 
                                          &target_mdl_request, &alter_ctx);
 
       my_free(const_cast<uchar*>(frm.str));
 
 
-      if (res)
 
+      if (res) {
 
+	sql_print_information("alter failed");
 
         DBUG_RETURN(true);
 
+      }
 
 
       goto end_inplace;
 
     }
 
diff --git a/storage/innobase/row/row0trunc.cc b/storage/innobase/row/row0trunc.cc
 
index 1dea23bc657..014970be951 100644
 
--- a/storage/innobase/row/row0trunc.cc
 
+++ b/storage/innobase/row/row0trunc.cc
 
@@ -1709,6 +1709,9 @@ row_truncate_table_for_mysql(
 
 #endif /* UNIV_DEBUG */
 
 	TruncateLogger*	logger = NULL;
 
 
+
 
+	ib::info() << "Truncate start " << table->name;
 
+
 
 	/* Understanding the truncate flow.
 
 
 	Step-1: Perform intiial sanity check to ensure table can be truncated.

Furthermore, in the TRUNCATE, we have only the clustered index in the table, and table->drop_aborted=FALSE.

I cannot see any fixes to this between MySQL 5.7.14 (which has been merged to MariaDB Server 10.2) and the currently latest published release 5.7.17. So, I guess that MySQL 5.7 should be affected as well.

If the TRUNCATE TABLE is replaced with DELETE FROM, there is no crash.

Comment by Marko Mäkelä [ 2017-02-07 ]

Actually the dict_v_col_t::v_indexes is empty as it should, but the problem is that dict_col_t::ord_part is not always cleared. There is a loop in rollback_inplace_alter_table() that tries to clear the flag. However, check_col_exists_in_indexes(prebuilt->table, i, true) sometimes holds when it should not.
Because rollback is not holding any lock, depending on concurrent (background) activity on the table, we may sometimes succeed in dropping the incompletely created unique secondary index, while sometimes it will remain as an ‘orphan’ index, to be dropped on the next opportunity. Because !table->drop_aborted at the start of TRUNCATE, that opportunity did arrive soon after the ALTER TABLE failed. But not soon enough for check_col_exists_in_indexes() to consider the virtual column as non-indexed.

The fix is that in rollback_inplace_alter_table(), we must only consider committed indexes when determining the appropriate state of the ord_part flag.

Comment by Marko Mäkelä [ 2017-02-07 ]

http://lists.askmonty.org/pipermail/commits/2017-February/010624.html

Comment by Jan Lindström (Inactive) [ 2017-02-07 ]

ok to push.

Generated at Thu Feb 08 07:54:20 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.