[MDEV-18162] Server crashes in dict_index_t::reconstruct_fields upon adding virtual column after dropping base columns Created: 2019-01-07  Updated: 2019-01-07  Resolved: 2019-01-07

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Storage Engine - InnoDB, Virtual Columns
Affects Version/s: 10.4
Fix Version/s: 10.4.2

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

Issue Links:
Relates
relates to MDEV-18160 Assertion `index->n_fields >= n_core'... Closed

 Description   

Note: The test case is very similar to MDEV-18160, it might be closely related to.

--source include/have_innodb.inc
 
CREATE TABLE `t1` (a INT, b INT, c INT) ENGINE=InnoDB;
INSERT INTO `t1` VALUES (2001,2001,1981),(2029,2029,2013);
 
ALTER TABLE `t1` DROP COLUMN c;
ALTER TABLE `t1` DROP COLUMN b;
ALTER TABLE `t1` ADD v INT AS (a);
 
# Cleanup
DROP TABLE t1;

10.4 ASAN 2465d3e00

ASAN:SIGSEGV
=================================================================
==16726==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000000 (pc 0x55c7e98a9098 sp 0x7f0ea55776a0 bp 0x7f0ea55776c0 T27)
    #0 0x55c7e98a9097 in dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}::operator()(dict_field_t const&) const (/data/bld/10.4-asan/bin/mysqld+0x23f4097)
    #1 0x55c7e98ac596 in bool __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>::operator()<dict_field_t*>(dict_field_t*) (/data/bld/10.4-asan/bin/mysqld+0x23f7596)
    #2 0x55c7e98ac0df in dict_field_t* std::__find_if<dict_field_t*, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}> >(__gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, std::random_access_iterator_tag) /usr/include/c++/4.9/bits/stl_algo.h:148
    #3 0x55c7e98ab179 in dict_field_t* std::__find_if<dict_field_t*, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}> >(__gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>) (/data/bld/10.4-asan/bin/mysqld+0x23f6179)
    #4 0x55c7e98aa8a1 in dict_field_t* std::find_if<dict_field_t*, dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>(dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}, dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}, dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}) (/data/bld/10.4-asan/bin/mysqld+0x23f58a1)
    #5 0x55c7e98a9b0e in dict_index_t::reconstruct_fields() /data/src/10.4/storage/innobase/dict/dict0mem.cc:1232
    #6 0x55c7e98a807c in dict_table_t::deserialise_columns(unsigned char const*, unsigned long) /data/src/10.4/storage/innobase/dict/dict0mem.cc:1313
    #7 0x55c7e976d4f6 in btr_cur_instant_init_low /data/src/10.4/storage/innobase/btr/btr0cur.cc:535
    #8 0x55c7e976dfe1 in btr_cur_instant_init(dict_table_t*) /data/src/10.4/storage/innobase/btr/btr0cur.cc:616
    #9 0x55c7e9899e56 in dict_load_table_one /data/src/10.4/storage/innobase/dict/dict0load.cc:3014
    #10 0x55c7e989872f in dict_load_table(char const*, bool, dict_err_ignore_t) /data/src/10.4/storage/innobase/dict/dict0load.cc:2766
    #11 0x55c7e98610fa in dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t) /data/src/10.4/storage/innobase/dict/dict0dict.cc:1185
    #12 0x55c7e93aa875 in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/storage/innobase/handler/handler0alter.cc:11065
    #13 0x55c7e8b4d91f in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/sql/handler.cc:4492
    #14 0x55c7e861610b in mysql_inplace_alter_table /data/src/10.4/sql/sql_table.cc:7590
    #15 0x55c7e8622f62 in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /data/src/10.4/sql/sql_table.cc:9690
    #16 0x55c7e876f9d7 in Sql_cmd_alter_table::execute(THD*) /data/src/10.4/sql/sql_alter.cc:497
    #17 0x55c7e8407fff in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6302
    #18 0x55c7e8412a12 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:8104
    #19 0x55c7e83ecf76 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1851
    #20 0x55c7e83e9ffe in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1396
    #21 0x55c7e87603c6 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1402
    #22 0x55c7e875fdd2 in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1308
    #23 0x55c7e92c61e9 in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
    #24 0x7f0eb0ce5493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
    #25 0x7f0eaf2e693e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
AddressSanitizer can not provide additional info.
SUMMARY: AddressSanitizer: SEGV ??:0 dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}::operator()(dict_field_t const&) const
Thread T27 created by T0 here:
    #0 0x7f0eb0f1ebba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
    #1 0x55c7e92c67b1 in spawn_thread_v1 /data/src/10.4/storage/perfschema/pfs.cc:1912
    #2 0x55c7e8144ca6 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
    #3 0x55c7e815aec4 in create_thread_to_handle_connection(CONNECT*) /data/src/10.4/sql/mysqld.cc:6436
    #4 0x55c7e815b5c9 in create_new_thread(CONNECT*) /data/src/10.4/sql/mysqld.cc:6506
    #5 0x55c7e815b959 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.4/sql/mysqld.cc:6623
    #6 0x55c7e815c5a5 in handle_connections_sockets() /data/src/10.4/sql/mysqld.cc:6788
    #7 0x55c7e815a381 in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:6058
    #8 0x55c7e8142b2f in main /data/src/10.4/sql/main.cc:25
    #9 0x7f0eaf21e2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
==16726==ABORTING

Both debug and non-debug builds also fail with SIGSEGV.

10.4 2465d3e00

#3  <signal handler called>
#4  0x0000560fd295c600 in dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}::operator()(dict_field_t const&) const (__closure=0x7fe9d20f0d70, o=...) at /data/src/10.4/storage/innobase/dict/dict0mem.cc:1232
#5  0x0000560fd295dee1 in __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>::operator()<dict_field_t*>(dict_field_t*) (this=0x7fe9d20f0d70, __it=0x7fe98407eed8) at /usr/include/c++/4.9/bits/predefined_ops.h:231
#6  0x0000560fd295dc51 in std::__find_if<dict_field_t*, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}> >(__gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, std::random_access_iterator_tag) (__first=0x7fe98407eed8, __last=0x7fe98407eef0, __pred=...) at /usr/include/c++/4.9/bits/stl_algo.h:148
#7  0x0000560fd295d368 in std::__find_if<dict_field_t*, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}> >(__gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>, __gnu_cxx::__ops::_Iter_pred<dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>) (__first=0x7fe98407eec0, __last=0x7fe98407eef0, __pred=...) at /usr/include/c++/4.9/bits/stl_algo.h:162
#8  0x0000560fd295cede in std::find_if<dict_field_t*, dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}>(dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}, dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}, dict_index_t::reconstruct_fields()::{lambda(dict_field_t const&)#1}) (__first=0x7fe98407eec0, __last=0x7fe98407eef0, __pred=...) at /usr/include/c++/4.9/bits/stl_algo.h:3804
#9  0x0000560fd295c958 in dict_index_t::reconstruct_fields (this=0x7fe984132638) at /data/src/10.4/storage/innobase/dict/dict0mem.cc:1232
#10 0x0000560fd295be73 in dict_table_t::deserialise_columns (this=0x7fe984084008, metadata=0x7fe9d28c0038 "", len=10) at /data/src/10.4/storage/innobase/dict/dict0mem.cc:1313
#11 0x0000560fd28abb24 in btr_cur_instant_init_low (index=0x7fe984132638, mtr=0x7fe9d20f1220) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:535
#12 0x0000560fd28ac01c in btr_cur_instant_init (table=0x7fe984084008) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:616
#13 0x0000560fd295483e in dict_load_table_one (name=..., cached=true, ignore_err=DICT_ERR_IGNORE_NONE, fk_tables=std::deque with 0 elements) at /data/src/10.4/storage/innobase/dict/dict0load.cc:3014
#14 0x0000560fd2953959 in dict_load_table (name=0x7fe9d20f2940 "test/t1", cached=true, ignore_err=DICT_ERR_IGNORE_NONE) at /data/src/10.4/storage/innobase/dict/dict0load.cc:2766
#15 0x0000560fd293543a in dict_table_open_on_name (table_name=0x7fe9d20f2940 "test/t1", dict_locked=1, try_drop=1, ignore_err=DICT_ERR_IGNORE_NONE) at /data/src/10.4/storage/innobase/dict/dict0dict.cc:1185
#16 0x0000560fd26a0c82 in ha_innobase::commit_inplace_alter_table (this=0x7fe98416c6f8, altered_table=0x7fe9841331a0, ha_alter_info=0x7fe9d20f3bc0, commit=true) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:11065
#17 0x0000560fd23301ec in handler::ha_commit_inplace_alter_table (this=0x7fe98416c6f8, altered_table=0x7fe9841331a0, ha_alter_info=0x7fe9d20f3bc0, commit=true) at /data/src/10.4/sql/handler.cc:4492
#18 0x0000560fd20efb94 in mysql_inplace_alter_table (thd=0x7fe984000b00, table_list=0x7fe984015090, table=0x7fe98416bac0, altered_table=0x7fe9841331a0, ha_alter_info=0x7fe9d20f3bc0, inplace_supported=HA_ALTER_INPLACE_INSTANT, target_mdl_request=0x7fe9d20f3cf0, alter_ctx=0x7fe9d20f48e0) at /data/src/10.4/sql/sql_table.cc:7590
#19 0x0000560fd20f59f5 in mysql_alter_table (thd=0x7fe984000b00, new_db=0x7fe9840051c8, new_name=0x7fe984005598, create_info=0x7fe9d20f54d0, table_list=0x7fe984015090, alter_info=0x7fe9d20f5410, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:9690
#20 0x0000560fd2180077 in Sql_cmd_alter_table::execute (this=0x7fe984015930, thd=0x7fe984000b00) at /data/src/10.4/sql/sql_alter.cc:497
#21 0x0000560fd201d319 in mysql_execute_command (thd=0x7fe984000b00) at /data/src/10.4/sql/sql_parse.cc:6302
#22 0x0000560fd2022244 in mysql_parse (thd=0x7fe984000b00, rawbuf=0x7fe984014f98 "ALTER TABLE `t1` ADD v INT AS (a)", length=33, parser_state=0x7fe9d20f6600, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
#23 0x0000560fd200f46e in dispatch_command (command=COM_QUERY, thd=0x7fe984000b00, packet=0x7fe984137fd1 "ALTER TABLE `t1` ADD v INT AS (a)", packet_length=33, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
#24 0x0000560fd200de92 in do_command (thd=0x7fe984000b00) at /data/src/10.4/sql/sql_parse.cc:1396
#25 0x0000560fd217a0ba in do_handle_one_connection (connect=0x560fd5eab7d0) at /data/src/10.4/sql/sql_connect.cc:1402
#26 0x0000560fd2179e3e in handle_one_connection (arg=0x560fd5eab7d0) at /data/src/10.4/sql/sql_connect.cc:1308
#27 0x0000560fd2639164 in pfs_spawn_thread (arg=0x560fd5ea6770) at /data/src/10.4/storage/perfschema/pfs.cc:1862
#28 0x00007fe9de8ac494 in start_thread (arg=0x7fe9d20f7700) at pthread_create.c:333
#29 0x00007fe9dcead93f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Not reproducible on 10.3.



 Comments   
Comment by Elena Stepanova [ 2019-01-07 ]

I have also seen this intermittent assertion failure with pretty much the same test case on the same non-ASAN debug build:

mysqld: /data/src/10.4/storage/innobase/dict/dict0mem.cc:1234: void dict_index_t::reconstruct_fields(): Assertion `old < &fields[n_fields]' failed.
190107 16:26:53 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f7c77437ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x000055fb184c2a40 in dict_index_t::reconstruct_fields (this=0x7f7c2807ee98) at /data/src/10.4/storage/innobase/dict/dict0mem.cc:1234
#9  0x000055fb184c1e73 in dict_table_t::deserialise_columns (this=0x7f7c28135488, metadata=0x7f7c70f48038 "", len=10) at /data/src/10.4/storage/innobase/dict/dict0mem.cc:1313
#10 0x000055fb18411b24 in btr_cur_instant_init_low (index=0x7f7c2807ee98, mtr=0x7f7c70777220) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:535
#11 0x000055fb1841201c in btr_cur_instant_init (table=0x7f7c28135488) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:616
#12 0x000055fb184ba83e in dict_load_table_one (name=..., cached=true, ignore_err=DICT_ERR_IGNORE_NONE, fk_tables=std::deque with 0 elements) at /data/src/10.4/storage/innobase/dict/dict0load.cc:3014
#13 0x000055fb184b9959 in dict_load_table (name=0x7f7c70778940 "test/t1", cached=true, ignore_err=DICT_ERR_IGNORE_NONE) at /data/src/10.4/storage/innobase/dict/dict0load.cc:2766
#14 0x000055fb1849b43a in dict_table_open_on_name (table_name=0x7f7c70778940 "test/t1", dict_locked=1, try_drop=1, ignore_err=DICT_ERR_IGNORE_NONE) at /data/src/10.4/storage/innobase/dict/dict0dict.cc:1185
#15 0x000055fb18206c82 in ha_innobase::commit_inplace_alter_table (this=0x7f7c2816c6f8, altered_table=0x7f7c281331a0, ha_alter_info=0x7f7c70779bc0, commit=true) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:11065
#16 0x000055fb17e961ec in handler::ha_commit_inplace_alter_table (this=0x7f7c2816c6f8, altered_table=0x7f7c281331a0, ha_alter_info=0x7f7c70779bc0, commit=true) at /data/src/10.4/sql/handler.cc:4492
#17 0x000055fb17c55b94 in mysql_inplace_alter_table (thd=0x7f7c28000b00, table_list=0x7f7c280150a0, table=0x7f7c2816bac0, altered_table=0x7f7c281331a0, ha_alter_info=0x7f7c70779bc0, inplace_supported=HA_ALTER_INPLACE_INSTANT, target_mdl_request=0x7f7c70779cf0, alter_ctx=0x7f7c7077a8e0) at /data/src/10.4/sql/sql_table.cc:7590
#18 0x000055fb17c5b9f5 in mysql_alter_table (thd=0x7f7c28000b00, new_db=0x7f7c280051c8, new_name=0x7f7c28005598, create_info=0x7f7c7077b4d0, table_list=0x7f7c280150a0, alter_info=0x7f7c7077b410, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:9690
#19 0x000055fb17ce6077 in Sql_cmd_alter_table::execute (this=0x7f7c28015970, thd=0x7f7c28000b00) at /data/src/10.4/sql/sql_alter.cc:497
#20 0x000055fb17b83319 in mysql_execute_command (thd=0x7f7c28000b00) at /data/src/10.4/sql/sql_parse.cc:6302
#21 0x000055fb17b88244 in mysql_parse (thd=0x7f7c28000b00, rawbuf=0x7f7c28014f98 "ALTER TABLE t1 ADD w DATE AS ( `col_date_key` )", length=47, parser_state=0x7f7c7077c600, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
#22 0x000055fb17b7546e in dispatch_command (command=COM_QUERY, thd=0x7f7c28000b00, packet=0x7f7c28137fd1 "ALTER TABLE t1 ADD w DATE AS ( `col_date_key` )", packet_length=47, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
#23 0x000055fb17b73e92 in do_command (thd=0x7f7c28000b00) at /data/src/10.4/sql/sql_parse.cc:1396
#24 0x000055fb17ce00ba in do_handle_one_connection (connect=0x55fb1b58b4c0) at /data/src/10.4/sql/sql_connect.cc:1402
#25 0x000055fb17cdfe3e in handle_one_connection (arg=0x55fb1b58b4c0) at /data/src/10.4/sql/sql_connect.cc:1308
#26 0x000055fb1819f164 in pfs_spawn_thread (arg=0x55fb1b586460) at /data/src/10.4/storage/perfschema/pfs.cc:1862
#27 0x00007f7c78ef3494 in start_thread (arg=0x7f7c7077d700) at pthread_create.c:333
#28 0x00007f7c774f493f in clone () from /lib/x86_64-linux-gnu/libc.so.6

I'm getting it while re-running the test below multiple times, but it only happens approx. once in 10 runs, the rest is the SIGSEGV from the description.

--source include/have_innodb.inc
 
CREATE TABLE t1 (
  col_date_key INT,
  col_date_nokey INT,
  col_datetime_key INT
) ENGINE=InnoDB;
INSERT INTO t1 VALUES (2001,2001,1981),(2029,2029,2013);
 
ALTER TABLE t1 DROP COLUMN `col_datetime_key`;
ALTER TABLE t1 DROP COLUMN `col_date_nokey`;
ALTER TABLE t1 ADD v INT AS ( `col_date_key` );
 
# Cleanup
DROP TABLE t1;

Comment by Marko Mäkelä [ 2019-01-07 ]

The problem appears to be that after the second DROP COLUMN, the previously instantly dropped column is not being identified as dropped in table->instant->field_map, like it should.

Comment by Marko Mäkelä [ 2019-01-07 ]

Simpler test case:

--source include/have_innodb.inc
CREATE TABLE t1 (a INT PRIMARY KEY, b INT, c INT) ENGINE=InnoDB;
INSERT INTO t1 SET a=1;
ALTER TABLE t1 DROP c;
ALTER TABLE t1 DROP b, ADD v INT AS (a);
DROP TABLE t1;

Comment by Marko Mäkelä [ 2019-01-07 ]

The problem is repeatable without virtual columns as well:

--source include/have_innodb.inc
CREATE TABLE t1 (a INT PRIMARY KEY, b INT, c INT) ENGINE=InnoDB;
INSERT INTO t1 SET a=1;
ALTER TABLE t1 DROP c;
ALTER TABLE t1 DROP b;
--source include/restart_mysqld.inc
DROP TABLE t1;

Comment by Marko Mäkelä [ 2019-01-07 ]

This is basically a follow-up fix to MDEV-18033/MDEV-18034, which was insufficient.

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