Bug #82320 ALTER Table failure with DUPLICATE key causes a crash
Submitted: 22 Jul 2016 8:33 Modified: 22 Jul 2016 8:52
Reporter: Krunal Bauskar Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.6, 5.6.31 OS:Any
Assigned to: CPU Architecture:Any

[22 Jul 2016 8:33] Krunal Bauskar
Description:
If ALTER table inplace operation fails with duplicate key error as show below in reproducible test-case server crashes.

How to repeat:

- Start mysqld server (using --debug_sync_timeout=1000 as we are using debug sync facility to stimulate the error)

- Open client connection-1 and try this
#conn-1
use test;
create table t1 (id int, a int, unique key uk(a)) engine = innodb;
insert into t1 select 1, 1;
insert into t1 select 2, 2;
SET DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL s1 WAIT_FOR s2';
alter table t1 add b int, ALGORITHM=inplace;

(ALTER WAIT at debug sync point)

- Open client connection-1a and try this
#conn-1a
use test;
SET DEBUG_SYNC = 'now WAIT_FOR s1';
insert into t1 select 3, 1;
SET DEBUG_SYNC = 'now SIGNAL s2';

(Check the server crash as below)

-------------

mysqld: xxx/storage/innobase/handler/handler0alter.cc:4000: virtual bool ha_innobase::inplace_alter_table(TABLE*, Alter_inplace_info*): Assertion `prebuilt->trx->error_key_num < ha_alter_info->key_count' failed.
08:25:04 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=2
max_threads=151
thread_count=2
connection_count=2
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68142 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x27ff440
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7fbfedf4ae60 thread_stack 0x40000
./bin/mysqld(my_print_stacktrace+0x47)[0xadf1ad]
./bin/mysqld(handle_fatal_signal+0x416)[0x738980]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10d10)[0x7fc01680bd10]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7fc015c39267]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fc015c3aeca]
/lib/x86_64-linux-gnu/libc.so.6(+0x2e03d)[0x7fc015c3203d]
/lib/x86_64-linux-gnu/libc.so.6(+0x2e0f2)[0x7fc015c320f2]
./bin/mysqld[0xbf369b]
./bin/mysqld(_ZN7handler22ha_inplace_alter_tableEP5TABLEP18Alter_inplace_info+0x35)[0x86f3fb]
./bin/mysqld[0x867817]
./bin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P24st_ha_create_informationP10TABLE_LISTP10Alter_infojP8st_orderb+0x1798)[0x86c027]
./bin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x57c)[0x9b6ce4]
./bin/mysqld(_Z21mysql_execute_commandP3THD+0x77af)[0x7f6396]
./bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x41b)[0x7f9a54]
./bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xc98)[0x7ec745]
./bin/mysqld(_Z10do_commandP3THD+0x35c)[0x7eb808]
./bin/mysqld(_Z24do_handle_one_connectionP3THD+0x1c5)[0x7b1027]
./bin/mysqld(handle_one_connection+0x33)[0x7b0b6d]
./bin/mysqld(pfs_spawn_thread+0x147)[0xb2f1b3]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76aa)[0x7fc0168026aa]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fc015d0aeed]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fbfc0004c00): alter table t1 add b int, ALGORITHM=inplace

Suggested fix:
DUPLICATE_KEY handling in handler0alter.cc show below is mixing up InnoDB context with MySQL context.

Let me explain. In the use-case above InnoDB add CLUSTER_INDEX key which has index-id = 0 and unique key has index-id = 1. MySQL context is not aware of this CLUSTER_INDEX so for MySQL context number of indexes is still 1.

        case DB_DUPLICATE_KEY:
...........
                } else {
                        DBUG_ASSERT(prebuilt->trx->error_key_num
                                    < ha_alter_info->key_count);
                        dup_key = &ha_alter_info->key_info_buffer[
                                prebuilt->trx->error_key_num];

                }

This creates a confusion. error_key_num = 1 as duplicate-key-violation happened for unique-index but ha_alter_info->key_count = 1.

Fix:
Should use following InnoDB context instead of ha_alter_info

        ha_innobase_inplace_ctx*        ctx
                = static_cast<ha_innobase_inplace_ctx*>
                (ha_alter_info->handler_ctx);
[22 Jul 2016 8:52] MySQL Verification Team
Hello Krunal,

Thank you for the report and test case.
Observed that 5.6.31 debug build is affected.

Thanks,
Umesh
[22 Jul 2016 8:52] MySQL Verification Team
-- 5.6.31 debug build

(gdb) bt
#0  0x00007fa620cbd771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000ae497f in my_write_core (sig=6) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/mysys/stacktrace.c:422
#2  0x000000000074724e in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007fa61f8c35d7 in raise () from /lib64/libc.so.6
#5  0x00007fa61f8c4cc8 in abort () from /lib64/libc.so.6
#6  0x00007fa61f8bc546 in __assert_fail_base () from /lib64/libc.so.6
#7  0x00007fa61f8bc5f2 in __assert_fail () from /lib64/libc.so.6
#8  0x0000000000b19f2f in ha_innobase::inplace_alter_table (this=0x7fa5cc01c750, altered_table=0x7fa5cc017880, ha_alter_info=0x7fa5f65b1810)
    at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/storage/innobase/handler/handler0alter.cc:3999
#9  0x0000000000872cda in handler::ha_inplace_alter_table (this=0x7fa5cc01c750, altered_table=0x7fa5cc017880, ha_alter_info=0x7fa5f65b1810)
    at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/handler.h:2874
#10 0x000000000086c0ee in mysql_inplace_alter_table (thd=0x30d2de0, table_list=0x7fa5cc0050d8, table=0x7fa5cc01be60, altered_table=0x7fa5cc017880, ha_alter_info=0x7fa5f65b1810,
    inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fa5f65b2170, alter_ctx=0x7fa5f65b0d60)
    at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_table.cc:6658
#11 0x000000000086dc9f in mysql_alter_table (thd=0x30d2de0, new_db=0x7fa5cc005638 "test", new_name=0x0, create_info=0x7fa5f65b2c10, table_list=0x7fa5cc0050d8, alter_info=0x7fa5f65b2cf0,
    order_num=0, order=0x0, ignore=false) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_table.cc:8511
#12 0x00000000009c0c35 in Sql_cmd_alter_table::execute (this=0x7fa5cc005708, thd=0x30d2de0) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_alter.cc:313
#13 0x0000000000803cf1 in mysql_execute_command (thd=0x30d2de0) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_parse.cc:4975
#14 0x000000000080468a in mysql_parse (thd=0x30d2de0, rawbuf=0x7fa5cc004fd0 "alter table t1 add b int, ALGORITHM=inplace", length=43, parser_state=0x7fa5f65b4700)
    at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_parse.cc:6385
#15 0x000000000080628b in dispatch_command (command=COM_QUERY, thd=0x30d2de0, packet=0x3202471 "alter table t1 add b int, ALGORITHM=inplace", packet_length=43)
    at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_parse.cc:1339
#16 0x0000000000807b13 in do_command (thd=0x30d2de0) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_parse.cc:1036
#17 0x00000000007bc759 in do_handle_one_connection (thd_arg=0x30d2de0) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_connect.cc:982
#18 0x00000000007bc81f in handle_one_connection (arg=0x30d2de0) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/sql/sql_connect.cc:898
#19 0x0000000000d90b32 in pfs_spawn_thread (arg=0x31e4050) at /export/home/pb2/build/sb_0-18928004-1463437877.21/mysqlcom-pro-5.6.31/storage/perfschema/pfs.cc:1860
#20 0x00007fa620cb8df5 in start_thread () from /lib64/libpthread.so.0
#21 0x00007fa61f98460d in clone () from /lib64/libc.so.6
(gdb)