handle_fatal_signal (sig=11) in free_root from TABLE_SHARE::destroy on ALTER TABLE t1 ADD COLUMN ... COLUMN_FORMAT COMPRESSED

[Roel Van de Paar]

Program terminated with signal 11, Segmentation fault.
#0 0x00007fee9e7eb741 in __pthread_kill (threadid=<optimized out>, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
61 val = INTERNAL_SYSCALL (tgkill, err, 3, THREAD_GETMEM (THREAD_SELF, pid),
(gdb) bt
+bt
#0 0x00007fee9e7eb741 in __pthread_kill (threadid=<optimized out>, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1 0x0000000000ac0e2a in my_write_core (sig=11) at /git/compression2_dbg/mysys/stacktrace.c:422
#2 0x00000000007360ff in handle_fatal_signal (sig=11) at /git/compression2_dbg/sql/signal_handler.cc:236
#3 <signal handler called>
#4 0x0000000000ab4fec in free_root (root=0x7fee9ed58c30, MyFlags=0) at /git/compression2_dbg/mysys/my_alloc.c:378
#5 0x00000000008ae898 in TABLE_SHARE::destroy (this=0x7fee67102410) at /git/compression2_dbg/sql/table.cc:499
#6 0x00000000008aea3d in free_table_share (share=0x7fee67102410) at /git/compression2_dbg/sql/table.cc:540
#7 0x0000000000772470 in table_def_free_entry (share=0x7fee67102410) at /git/compression2_dbg/sql/sql_base.cc:351
#8 0x0000000000aa1ba7 in my_hash_delete (hash=0x179a0a0 <table_def_cache>, record=0x7fee67102410 '\217' <repeats 1008 times>, "\222h\245 ") at /git/compression2_dbg/mysys/hash.c:603
#9 0x0000000000772e18 in release_table_share (share=0x7fee67102410) at /git/compression2_dbg/sql/sql_base.cc:682
#10 0x00000000008b42d3 in closefrm (table=0x7fee67069c00, free_share=true) at /git/compression2_dbg/sql/table.cc:2528
#11 0x00000000007733c2 in intern_close_table (table=0x7fee67069c00) at /git/compression2_dbg/sql/sql_base.cc:817
#12 0x000000000077491b in close_thread_table (thd=0x7fee6eacf000, table_ptr=0x7fee6eacf0d0) at /git/compression2_dbg/sql/sql_base.cc:1521
#13 0x00000000007742b2 in close_all_tables_for_name (thd=0x7fee6eacf000, share=0x7fee67102410, remove_from_locked_tables=false, skip_table=0x0) at /git/compression2_dbg/sql/sql_base.cc:1297
#14 0x000000000085f5be in mysql_inplace_alter_table (thd=0x7fee6eacf000, table_list=0x7fee6701f148, table=0x7fee67069c00, altered_table=0x7fee6711ea00, ha_alter_info=0x7fee9ed59810, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fee9ed59260, alter_ctx=0x7fee9ed59d70) at /git/compression2_dbg/sql/sql_table.cc:6913
#15 0x00000000008643a4 in mysql_alter_table (thd=0x7fee6eacf000, new_db=0x7fee6701f6a8 "test", new_name=0x0, create_info=0x7fee9ed5ac30, table_list=0x7fee6701f148, alter_info=0x7fee9ed5ab70, order_num=0, order=0x0, ignore=false) at /git/compression2_dbg/sql/sql_table.cc:8943
#16 0x00000000009ac859 in Sql_cmd_alter_table::execute (this=0x7fee6701f788, thd=0x7fee6eacf000) at /git/compression2_dbg/sql/sql_alter.cc:317
#17 0x00000000007f1361 in mysql_execute_command (thd=0x7fee6eacf000) at /git/compression2_dbg/sql/sql_parse.cc:5528
#18 0x00000000007f4ab1 in mysql_parse (thd=0x7fee6eacf000, rawbuf=0x7fee6701f010 "ALTER TABLE t1 ADD COLUMN c VARCHAR(1000) COLUMN_FORMAT COMPRESSED", length=66, parser_state=0x7fee9ed5c500) at /git/compression2_dbg/sql/sql_parse.cc:7002
#19 0x00000000007e6768 in dispatch_command (command=COM_QUERY, thd=0x7fee6eacf000, packet=0x7fee6ead3001 "ALTER TABLE t1 ADD COLUMN c VARCHAR(1000) COLUMN_FORMAT COMPRESSED;", packet_length=67) at /git/compression2_dbg/sql/sql_parse.cc:1450
#20 0x00000000007e5609 in do_command (thd=0x7fee6eacf000) at /git/compression2_dbg/sql/sql_parse.cc:1058
#21 0x00000000007acbad in do_handle_one_connection (thd_arg=0x7fee7472f000) at /git/compression2_dbg/sql/sql_connect.cc:1541
#22 0x00000000007ac62d in handle_one_connection (arg=0x7fee7472f000) at /git/compression2_dbg/sql/sql_connect.cc:1444
#23 0x0000000000b0f8cd in pfs_spawn_thread (arg=0x7fee843ff2e0) at /git/compression2_dbg/storage/perfschema/pfs.cc:1860
#24 0x00007fee9e7e6dc5 in start_thread (arg=0x7fee9ed5d700) at pthread_create.c:308
#25 0x00007fee9cc43ced in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

ALTER TABLE t1 ADD COLUMN c VARCHAR(1000) COLUMN_FORMAT COMPRESSED;

Testcase will follow tomorrow. Sporadic but highly present. qablocker.

[Roel Van de Paar (roel11)]

Similar stack from other trial

+bt
#0 0x00007f3143b3f741 in __pthread_kill (threadid=<optimized out>, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1 0x0000000000ac0e2a in my_write_core (sig=11) at /git/compression2_dbg/mysys/stacktrace.c:422
#2 0x00000000007360ff in handle_fatal_signal (sig=11) at /git/compression2_dbg/sql/signal_handler.cc:236
#3 <signal handler called>
#4 0x0000000000ab4f8f in free_root (root=0x7f31440edc30, MyFlags=0) at /git/compression2_dbg/mysys/my_alloc.c:368
#5 0x00000000008ae898 in TABLE_SHARE::destroy (this=0x7f310c0f6410) at /git/compression2_dbg/sql/table.cc:499
#6 0x00000000008aea3d in free_table_share (share=0x7f310c0f6410) at /git/compression2_dbg/sql/table.cc:540
#7 0x0000000000772470 in table_def_free_entry (share=0x7f310c0f6410) at /git/compression2_dbg/sql/sql_base.cc:351
#8 0x0000000000aa1ba7 in my_hash_delete (hash=0x179a0a0 <table_def_cache>, record=0x7f310c0f6410 '\217' <repeats 1500 times>...) at /git/compression2_dbg/mysys/hash.c:603
#9 0x0000000000772e18 in release_table_share (share=0x7f310c0f6410) at /git/compression2_dbg/sql/sql_base.cc:682
#10 0x00000000008b42d3 in closefrm (table=0x7f310c066000, free_share=true) at /git/compression2_dbg/sql/table.cc:2528
#11 0x00000000007733c2 in intern_close_table (table=0x7f310c066000) at /git/compression2_dbg/sql/sql_base.cc:817
#12 0x000000000077491b in close_thread_table (thd=0x7f3113ecd000, table_ptr=0x7f3113ecd0d0) at /git/compression2_dbg/sql/sql_base.cc:1521
#13 0x00000000007742b2 in close_all_tables_for_name (thd=0x7f3113ecd000, share=0x7f310c0f6410, remove_from_locked_tables=false, skip_table=0x0) at /git/compression2_dbg/sql/sql_base.cc:1297
#14 0x000000000085f5be in mysql_inplace_alter_table (thd=0x7f3113ecd000, table_list=0x7f310c01f148, table=0x7f310c066000, altered_table=0x7f310c118e00, ha_alter_info=0x7f31440ee810, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f31440ee260, alter_ctx=0x7f31440eed70) at /git/compression2_dbg/sql/sql_table.cc:6913
#15 0x00000000008643a4 in mysql_alter_table (thd=0x7f3113ecd000, new_db=0x7f310c01f6a8 "test", new_name=0x0, create_info=0x7f31440efc30, table_list=0x7f310c01f148, alter_info=0x7f31440efb70, order_num=0, order=0x0, ignore=false) at /git/compression2_dbg/sql/sql_table.cc:8943
#16 0x00000000009ac859 in Sql_cmd_alter_table::execute (this=0x7f310c01f788, thd=0x7f3113ecd000) at /git/compression2_dbg/sql/sql_alter.cc:317
#17 0x00000000007f1361 in mysql_execute_command (thd=0x7f3113ecd000) at /git/compression2_dbg/sql/sql_parse.cc:5528
#18 0x00000000007f4ab1 in mysql_parse (thd=0x7f3113ecd000, rawbuf=0x7f310c01f010 "ALTER TABLE t1 ADD COLUMN c VARCHAR(1000) COLUMN_FORMAT COMPRESSED", length=66, parser_state=0x7f31440f1500) at /git/compression2_dbg/sql/sql_parse.cc:7002
#19 0x00000000007e6768 in dispatch_command (command=COM_QUERY, thd=0x7f3113ecd000, packet=0x7f3113ed1001 "ALTER TABLE t1 ADD COLUMN c VARCHAR(1000) COLUMN_FORMAT COMPRESSED;", packet_length=67) at /git/compression2_dbg/sql/sql_parse.cc:1450
#20 0x00000000007e5609 in do_command (thd=0x7f3113ecd000) at /git/compression2_dbg/sql/sql_parse.cc:1058
#21 0x00000000007acbad in do_handle_one_c...

[Roel Van de Paar (roel11)]

2016-09-12 21:52:00 23400 [Note] Event Scheduler: scheduler thread started with id 1
InnoDB: Apparent memory corruption: mem dump len 500; hex 8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f07952d00000000306d656d2e6363000a020000000000008f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8f8fc0e9000c317f00000000000000000000a003000000000000ffffffffffffffff0000000000000000a003000000000000780000000000000000000000000000000000000000000000a20200000000000078f6f626317f0000787cbd26317f0000c0e9000c317f000078f8020c317f000078b0010c317f0000f8c4060c317f0000af020000ffffffff8101000001104000010400000000000088f8020c317f00000000000000000000000000000000000008f9020c317f00000000000000000000f0f8020c317f0000f8f8; asc - 0mem.cc 1 x x &1 x| &1 1 x 1 x 1 1 @ 1 1 1 ;
InnoDB: Scanning backward trying to find previous allocated mem blocks
Freed mem block at - 3072, file 0mem.cc, line 522
Mem block at - 9216, file 0mem.cc, line 522
Mem block at - 10240, file 0mem.cc, line 522
Freed mem block at - 41536, file 0cur.ic, line 267
Freed mem block at - 41856, file 0cur.ic, line 291608088757141771
Freed mem block at - 42496, file nodb.cc, line 7257
Freed mem block at - 42816, file 0cur.ic, line 267
Freed mem block at - 43136, file 0cur.cc, line 76279731573492008
Freed mem block at - 82816, file 0fil.cc, line 1334
Mem block at - 83712, file 0fil.cc, line 1334
InnoDB: Scanning forward trying to find next allocated mem blocks
Freed mem block at + 2048, file 0mem.cc, line 522
Freed mem block at + 24576, file 0mem.cc, line 522
Freed mem block at + 54016, file page.cc, line 372
Freed mem block at + 57856, file page.cc, line 372
Freed mem block at + 58624, file page.cc, line 372
Mem block at + 90240, file 0mem.ic, line 616
Freed mem block at + 90368, file eval.cc, line 90
Freed mem block at + 90752, file eval.cc, line 90
Freed mem block at + 90880, file eval.cc, line 90
Freed mem block at + 91008, file eval.cc, line 90
11:52:21 UTC - mysqld got signal 11 ;

[Yura Sorokin (yura-sorokin)]

"TABLE_SHARE::destroy()" used to unconditionally destroy "zip_dict_data" and "zip_dict_data" in field definitions. These fields could have been left with garbage if "open_table()" returned an error.

"innodb.xtradb_compressed_columns" MTR test case extended with steps provided in this bug.

Fixed in the initial "compressed_columns" commit
https://github.com/percona/percona-server/pull/735

[Yura Sorokin (yura-sorokin)]

this is similar to
https://bugs.launchpad.net/percona-server/+bug/1621684

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-394