[MDEV-9918] [ERROR] mysqld got signal 11 during ALTER TABLE `name` COLUMN ADD Created: 2016-04-14  Updated: 2016-06-23  Resolved: 2016-04-22

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.1.13, 10.0, 10.1
Fix Version/s: 10.0.25, 10.1.14

Type: Bug Priority: Major
Reporter: JarosÅ‚aw Siebert Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: upstream
Environment:

Server version: 10.1.13-MariaDB
key_buffer_size=16777216
read_buffer_size=262144
max_used_connections=4
max_threads=153
thread_count=2

OS: Alpinelinux 3.3.3 based on musl-libc running as guest on kvm host (Alpinelinux).

Sprint: 10.0.25

 Description   

From mariadb log:

2016-04-14  4:58:03 140116923128496 [ERROR] Table ./csm/history_digital185410 has a primary key in InnoDB data dictionary, but not in MySQL!
 
2016-04-14  4:58:03 140116923128496 [ERROR] InnoDB: Table csm/history_digital185410 contains 2 indexes inside InnoDB, which is different from the number of indexes 1 defined in the MySQL 
2016-04-14  4:58:03 140116923128496 [Note] InnoDB: Online DDL : Start
 
2016-04-14  4:58:03 140116923128496 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
 
160414  4:58:03 [ERROR] mysqld got signal 11 ;
 
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.

The database crashed many times during altering tables.
There is over 400000 small tables in this database, and I wish to alter about 220000 tables.
RAM memory in system: 4GB.
Storage used for database: about 31GB

 Comments   
Comment by Jarosław Siebert [ 2016-04-14 ]

I would like to add some more details about this case.
1. This is probably related with hardware problems (one hard drive was corrupted and i have replaced it, but
didn't recovery from backup as I didn't noticed any problem with services before.
2. When I do select * from `corrupted_table`; I get right results.
3. When I do describe `corrupted_table`; I get mysqld got signal 11
4. When I do drop table `corrupted_table`; the table is droped
5. When I create `corrupted_table` and insert data, everything works fine.
So I fixed the problem in my case by drop and create table that cused the problems.

Comment by Elena Stepanova [ 2016-04-15 ]

Even though the reason is inconsistent data due to a previous disk failure, crashing is not a desirable behavior.

Stack trace from 10.1 debug commit 4b6a3518e4dc9088d1f42cd9bc487d06137d2760

 
2016-04-15 16:49:31 7f2456396b00  InnoDB: Assertion failure in thread 139794042153728 in file row0merge.cc line 583
 
InnoDB: Failing assertion: !(col->prtype & 256)
 
 
 
#5  0x00007f24540d7538 in abort () from /lib64/libc.so.6
 
#6  0x00007f244d7f9e78 in row_merge_buf_add (buf=0x7f243fa29f78, fts_index=0x0, old_table=0x7f243fab62f8, psort_info=0x0, row=0x7f243fba6c80, ext=0x0, doc_id=0x7f2456391bc0, conv_heap=0x0, exceed_page=0x7f2456391bad) at /src/10.1/storage/innobase/row/row0merge.cc:583
 
#7  0x00007f244d7fd0a2 in row_merge_read_clustered_index (trx=0x7f243fa41278, table=0x7f243fa5f470, old_table=0x7f243fab62f8, new_table=0x7f243fab6578, online=true, index=0x7f243fa1d470, fts_sort_idx=0x0, psort_info=0x0, files=0x7f243fa35518, key_numbers=0x7f243fa1d478, n_index=1, add_cols=0x7f243fa1d4c8, col_map=0x7f243fa1d590, add_autoinc=18446744073709551615, sequence=..., block=0x7f243f500000 "", tmpfd=0x7f245639241c, pct_cost=50, crypt_data=0x0, crypt_block=0x0) at /src/10.1/storage/innobase/row/row0merge.cc:1906
 
#8  0x00007f244d802004 in row_merge_build_indexes (trx=0x7f243fa41278, old_table=0x7f243fab62f8, new_table=0x7f243fab6578, online=true, indexes=0x7f243fa1d470, key_numbers=0x7f243fa1d478, n_indexes=1, table=0x7f243fa5f470, add_cols=0x7f243fa1d4c8, col_map=0x7f243fa1d590, add_autoinc=18446744073709551615, sequence=...) at /src/10.1/storage/innobase/row/row0merge.cc:4079
 
#9  0x00007f244d72ac50 in ha_innodb::inplace_alter_table (this=0x7f243f835888, altered_table=0x7f243fa5f470, ha_alter_info=0x7f2456392a80) at /src/10.1/storage/innobase/handler/handler0alter.cc:4161
 
#10 0x0000560f5fc09acd in handler::ha_inplace_alter_table (this=0x7f243f835888, altered_table=0x7f243fa5f470, ha_alter_info=0x7f2456392a80) at /src/10.1/sql/handler.h:3686
 
#11 0x0000560f5fc01cbc in mysql_inplace_alter_table (thd=0x7f244c4f3430, table_list=0x7f243fa526a8, table=0x7f243fa4cc70, altered_table=0x7f243fa5f470, ha_alter_info=0x7f2456392a80, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f2456392af0, alter_ctx=0x7f2456393690) at /src/10.1/sql/sql_table.cc:7105
 
#12 0x0000560f5fc06508 in mysql_alter_table (thd=0x7f244c4f3430, new_db=0x7f243fa52c98 "test", new_name=0x0, create_info=0x7f2456394280, table_list=0x7f243fa526a8, alter_info=0x7f24563941f0, order_num=0, order=0x0, ignore=false) at /src/10.1/sql/sql_table.cc:8917
 
#13 0x0000560f5fc76881 in Sql_cmd_alter_table::execute (this=0x7f243fa52d88, thd=0x7f244c4f3430) at /src/10.1/sql/sql_alter.cc:325
 
#14 0x0000560f5fb4a7a4 in mysql_execute_command (thd=0x7f244c4f3430) at /src/10.1/sql/sql_parse.cc:5679
 
#15 0x0000560f5fb4e9c2 in mysql_parse (thd=0x7f244c4f3430, rawbuf=0x7f243fa525c8 "alter table t1 add j int", length=24, parser_state=0x7f24563955e0) at /src/10.1/sql/sql_parse.cc:7304
 
#16 0x0000560f5fb3d3c3 in dispatch_command (command=COM_QUERY, thd=0x7f244c4f3430, packet=0x7f244ff874b1 "alter table t1 add j int", packet_length=24) at /src/10.1/sql/sql_parse.cc:1486
 
#17 0x0000560f5fb3c0f5 in do_command (thd=0x7f244c4f3430) at /src/10.1/sql/sql_parse.cc:1107
 
#18 0x0000560f5fc71e34 in do_handle_one_connection (thd_arg=0x7f244c4f3430) at /src/10.1/sql/sql_connect.cc:1349
 
#19 0x0000560f5fc71b98 in handle_one_connection (arg=0x7f244c4f3430) at /src/10.1/sql/sql_connect.cc:1261
 
#20 0x0000560f6037a598 in pfs_spawn_thread (arg=0x7f244c782e70) at /src/10.1/storage/perfschema/pfs.cc:1860
 
#21 0x00007f24560180a4 in start_thread () from /lib64/libpthread.so.0

Stack trace from 10.1.13 release bintar

 
2  <signal handler called>
 
#3  0x00007f05ebe2ee10 in __memcpy_sse2_unaligned () from /lib64/libc.so.6
 
#4  0x00007f05e50be475 in memcpy (__src=<optimized out>, __dest=<optimized out>, __len=4294967295) at /usr/include/x86_64-linux-gnu/bits/string3.h:52
 
#5  rec_convert_dtuple_to_rec_comp (temp=false, status=0, n_fields=6, fields=0x7f05d6567228, index=0x7f05d642e9e8, rec=0x7f05eb888006 "\200") at /home/buildbot/buildbot/build/storage/innobase/rem/rem0rec.cc:1291
 
#6  rec_convert_dtuple_to_temp (rec=0x7f05eb888006 "\200", index=0x7f05d642e9e8, fields=0x7f05d6567228, n_fields=6) at /home/buildbot/buildbot/build/storage/innobase/rem/rem0rec.cc:1426
 
#7  0x00007f05e50d63f1 in row_merge_buf_encode (n_fields=6, entry=0x7f05d668d000, index=0x7f05d642e9e8, b=<synthetic pointer>) at /home/buildbot/buildbot/build/storage/innobase/row/row0merge.cc:231
 
#8  row_merge_buf_write (buf=buf@entry=0x7f05d66511c8, of=of@entry=0x7f05d6663968, block=block@entry=0x7f05eb888000 "") at /home/buildbot/buildbot/build/storage/innobase/row/row0merge.cc:874
 
#9  0x00007f05e50d6fce in row_merge_read_clustered_index (trx=trx@entry=0x7f05d653fa68, table=table@entry=0x7f05d6669008, old_table=old_table@entry=0x7f05d642d5e8, new_table=new_table@entry=0x7f05d642d868, online=online@entry=true, index=0x0, index@entry=0x7f05d641e760, fts_sort_idx=fts_sort_idx@entry=0x0, psort_info=0x0, files=files@entry=0x7f05d6663968, key_numbers=key_numbers@entry=0x7f05d641e768, n_index=n_index@entry=1, add_cols=add_cols@entry=0x7f05d641e7b8, col_map=col_map@entry=0x7f05d641e878, add_autoinc=add_autoinc@entry=18446744073709551615, sequence=..., block=block@entry=0x7f05eb888000 "", tmpfd=tmpfd@entry=0x7f05ed3944f0, pct_cost=pct_cost@entry=50, crypt_data=crypt_data@entry=0x0, crypt_block=crypt_block@entry=0x0) at /home/buildbot/buildbot/build/storage/innobase/row/row0merge.cc:2012
 
#10 0x00007f05e50dcd2a in row_merge_build_indexes (trx=0x7f05d653fa68, old_table=0x7f05d642d5e8, new_table=0x7f05d642d868, online=true, indexes=0x7f05d641e760, key_numbers=0x7f05d641e768, n_indexes=1, table=table@entry=0x7f05d6669008, add_cols=0x7f05d641e7b8, col_map=0x7f05d641e878, add_autoinc=18446744073709551615, sequence=...) at /home/buildbot/buildbot/build/storage/innobase/row/row0merge.cc:4079
 
#11 0x00007f05e5047edd in ha_innodb::inplace_alter_table (this=0x7f05d6627020, altered_table=0x7f05d6669008, ha_alter_info=0x7f05ed395050) at /home/buildbot/buildbot/build/storage/innobase/handler/handler0alter.cc:4161
 
#12 0x0000556311980d41 in ha_inplace_alter_table (ha_alter_info=0x7f05ed395050, altered_table=0x7f05d6669008, this=<optimized out>) at /home/buildbot/buildbot/build/sql/handler.h:3686
 
#13 mysql_inplace_alter_table (thd=thd@entry=0x7f05e2289008, table_list=0x7f05d64c5100, table=table@entry=0x7f05d6459808, altered_table=altered_table@entry=0x7f05d6669008, ha_alter_info=ha_alter_info@entry=0x7f05ed395050, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, alter_ctx=alter_ctx@entry=0x7f05ed395c60, target_mdl_request=0x7f05ed3950c0) at /home/buildbot/buildbot/build/sql/sql_table.cc:7105
 
#14 0x0000556311abc3bd in mysql_alter_table (thd=0x7f05e2289000, thd@entry=0x7f05e2289008, new_db=<optimized out>, new_name=<optimized out>, create_info=create_info@entry=0x7f05ed396820, table_list=table_list@entry=0x7f05d64c5100, alter_info=alter_info@entry=0x7f05ed396790, order_num=0, order=0x0, ignore=false) at /home/buildbot/buildbot/build/sql/sql_table.cc:8917
 
#15 0x0000556311afd947 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7f05e2289008) at /home/buildbot/buildbot/build/sql/sql_alter.cc:325
 
#16 0x0000556311a33dcf in mysql_execute_command (thd=thd@entry=0x7f05e2289008) at /home/buildbot/buildbot/build/sql/sql_parse.cc:5679
 
#17 0x0000556311a3bd2d in mysql_parse (thd=0x7f05e2289008, rawbuf=<optimized out>, length=<optimized out>, parser_state=0x7f05ed398600) at /home/buildbot/buildbot/build/sql/sql_parse.cc:7304
 
#18 0x0000556311a3e97b in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f05e2289008, packet=0x7f05e22c0009 "alter table t1 add j int", packet_length=3595325472, packet_length@entry=24) at /home/buildbot/buildbot/build/sql/sql_parse.cc:1486
 
#19 0x0000556311a3ef2b in do_command (thd=0x7f05e2289008) at /home/buildbot/buildbot/build/sql/sql_parse.cc:1107
 
#20 0x0000556311afa7bf in do_handle_one_connection (thd_arg=thd_arg@entry=0x7f05e2289008) at /home/buildbot/buildbot/build/sql/sql_connect.cc:1349
 
#21 0x0000556311afa917 in handle_one_connection (arg=arg@entry=0x7f05e2289008) at /home/buildbot/buildbot/build/sql/sql_connect.cc:1261
 
#22 0x0000556311f3223d in pfs_spawn_thread (arg=0x7f05eb03f608) at /home/buildbot/buildbot/build/storage/perfschema/pfs.cc:1860
 
#23 0x00007f05ec7d10a4 in start_thread () from /lib64/libpthread.so.0

Also reproducible on MySQL 5.6, MySQL 5.7.

MTR test case

 
--source include/have_innodb.inc
 
 
 
create table t1 (pk int, i int, key(i)) engine=InnoDB;
 
insert into t1 values (1,1),(2,2);
 
 
 
--let $datadir= `select @@datadir`
 
 
 
flush tables;
 
 
 
--echo # Save the .frm file without the PK
 
 
 
--copy_file $datadir/test/t1.frm $MYSQLTEST_VARDIR/tmp/t1.frm
 
 
 
alter table t1 add primary key (pk);
 
 
 
--echo # Stop the server, replace the frm with the old one and restart the server
 
 
 
--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
 
--shutdown_server 10
 
--source include/wait_until_disconnected.inc
 
 
 
--remove_file $datadir/test/t1.frm
 
--copy_file $MYSQLTEST_VARDIR/tmp/t1.frm $datadir/test/t1.frm
 
 
 
--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
 
--enable_reconnect
 
--source include/wait_until_connected_again.inc
 
 
 
select * from t1;
 
alter table t1 add j int;
 
 
 
# Cleanup
 
drop table t1;

Comment by Jan Lindström (Inactive) [ 2016-04-22 ]

commit f8adeccd78bff80725a95b73447e34a5f4528179
Author: Elena Stepanova <elenst@montyprogram.com>
Date: Mon Apr 4 17:04:14 2016 +0300

MDEV-9713 Sporadic test failure: sys_vars.innodb_buffer_pool_load_now_basic

Previous fix using wait condition did not work because of MDEV-9867, so
we have to use conditional sleep instead. Sleep will only happen if the test
is executed after another one which also ran buffer pool dump without
server restart between two tests.

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