Bug #28477 innodb assertion and crash during alter table to add/drop partitions
Submitted: 16 May 2007 17:05 Modified: 10 Jul 2009 13:54
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Partitions Severity:S1 (Critical)
Version:5.1.19, 5.1.17, 5.1.36 OS:Any
Assigned to: Alexey Botchkov CPU Architecture:Any
Tags: assertion, crash, innodb, partition

[16 May 2007 17:05] Shane Bester
Description:
Seems altering partition layouts isn't all that safe when done in parallel with other accesses to the table.  The data dictionary gets out of sync.

The testcase crashes my 5.1 debug server, and may cause infinite hangs on a non-debug server :

InnoDB: The first specified data file ./ibdata1 did not exist:
InnoDB: a new database to be created!
070516 18:46:17  InnoDB: Setting file ./ibdata1 size to 10 MB
InnoDB: Database physically writes the file full: wait...
070516 18:46:18  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 5 MB
InnoDB: Database physically writes the file full: wait...
070516 18:46:19  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 5 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Doublewrite buffer not found: creating new
InnoDB: Doublewrite buffer created
InnoDB: Creating foreign key constraint system tables
InnoDB: Foreign key constraint system tables created
070516 18:46:20  InnoDB: Started; log sequence number 0 0
070516 18:46:20 [Note] /home/sbester/server/5.1/mysql-5.1.19-beta-linux-i686/bin/mysqld: ready for connections.
Version: '5.1.19-beta-debug'  socket: '/tmp/mysql.sock'  port: 3306  yes
070516 18:47:51  InnoDB: Error: table `test`.070516 18:47:51 [ERROR] Invalid (old?) table or database name 't1_test#P#p08'
`#mysql50#t1_test#P#p08` already exists in InnoDB internal
InnoDB: data dictionary. Have you deleted the .frm file
InnoDB: and not used DROP TABLE? Have you used DROP DATABASE
InnoDB: for InnoDB tables in MySQL version <= 3.23.43?
InnoDB: See the Restrictions section of the InnoDB manual.
InnoDB: You can drop the orphaned table inside InnoDB by
InnoDB: creating an InnoDB table with the same name in another
InnoDB: database and copying the .frm file to the current database.
InnoDB: Then MySQL thinks the table exists, and DROP TABLE will
InnoDB: succeed.
InnoDB: You can look for further help from
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/innodb-troubleshooting.html
070516 18:47:51  InnoDB: Assertion failure in thread 1113844656 in file row0mysql.c line 1638
InnoDB: Failing assertion: index
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
070516 18:47:51 - 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=8388600
read_buffer_size=131072
max_used_connections=4
max_threads=151
threads_connected=3
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337611 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x8dff748
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...
Cannot determine thread, fp=0x4263744c, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x81f8838 handle_segfault + 792
0xffffe410 _end + -142301952
0x400edb75 _end + 932420709
0x84412e5 row_get_mysql_key_number_for_index + 101
0x8408ef3 _ZN11ha_innobase4infoEj + 659
0x830ff1c _ZN7handler11print_errorEii + 2300
0x831a18d _ZN12ha_partition11print_errorEii + 173
0x811517b _Z23mysql_change_partitionsP18st_lock_param_type + 251
0x81167ab _Z26fast_alter_partition_tableP3THDP8st_tableP13st_alter_infoP24st_ha_create_informationP13st_table_listP4ListI12create_fieldEP + 2155
0x833297f _Z17mysql_alter_tableP3THDPcS1_P24st_ha_create_informationP13st_table_listR4ListI12create_fieldERS6_I3KeyEjP8st_orderbP13st_alt + 11487
0x8212a9e _Z21mysql_execute_commandP3THD + 35214
0x83b0011 _ZN13sp_instr_stmt9exec_coreEP3THDPj + 17
0x83b03a9 _ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr + 313
0x83b1019 _ZN13sp_instr_stmt7executeEP3THDPj + 1593
0x83b4220 _ZN7sp_head7executeEP3THD + 1632
0x83b4c92 _ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE + 1298
0x821172a _Z21mysql_execute_commandP3THD + 30234
0x8213554 _Z11mysql_parseP3THDPcj + 612
0x8214562 _Z16dispatch_command19enum_server_commandP3THDPcj + 3762
0x8215375 _Z10do_commandP3THD + 421
0x820264f handle_one_connection + 271
0x4004daa7 _end + 931765143
0x4017ec2e _end + 933014814
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do 
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8e03e58 = alter table t1_test add partition (partition `p08` values less than (200000))
thd->thread_id=3
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.

Number of processes running now: 1
mysqld process hanging, pid 16466 - killed
070516 18:47:52  mysqld restarted
070516 18:47:52  mysqld ended

How to repeat:
rm -rf your datadir and run ./mysql-install-db to start fresh
./bin/mysqld_safe --skip-grant-tables --skip-name-resolve &
Just open 3 or more mysql command line clients and paste the following:

###
flush tables;
drop table if exists t1_test;
create table t1_test(id int not null,name varchar(25),data tinyblob,key(name),key(id)) engine=innodb partition by range(id) ( partition p00 values less than (5000));
drop procedure if exists p1;
delimiter //
create procedure p1()
begin
        declare counter int default 0;
        declare continue handler for sqlexception begin end;
        repeat
                insert into t1_test values (floor(10000*rand()),'aaaaaaa','bbbbbbb');
                alter table t1_test add partition (partition `p08` values less than (200000));
                alter table t1_test drop partition p08;
                set counter=counter+1;
        until counter > 1000000
        end repeat;

end //

delimiter ;

call p1();

####
[16 May 2007 17:32] Shane Bester
verified on suse 9.3 using latest 5.1-bk source.
[20 May 2007 13:47] Shane Bester
I'mnot sure this is really an innodb bug.  It seems you cannot do an optimize/repair/rebuild of a partition with myisam tables either, as long as inserts are happening in another thread.

set category to 'Partitioning' instead.
[21 May 2007 7:49] Shane Bester
when fixing the bugs, please use *this* testcase to verify your fixes work.

Attachment: bug28477.c (text/plain), 6.03 KiB.

[27 May 2007 13:12] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/27408

ChangeSet@1.2535, 2007-05-27 18:16:13+05:00, holyfoot@mysql.com +1 -0
  Bug #28477 innodb assertion and crash during alter table to add/drop partition.
  
  The bug was repeated on MyISAM tables, so isn't InnoDB specific.
  The reason is that open_ltable() called in mysql_alter_table
  doesn't check if the opened table was modified by other thread
  before it was locked by mysql_lock_tables().
  mysql_lock_tables() can signal that case by setting it's 'need_reopen'
  parameter to TRUE. So check for that parameter added.
[1 Jun 2007 15:03] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/27933

ChangeSet@1.2535, 2007-06-01 19:00:22+05:00, holyfoot@mysql.com +1 -0
  Bug #28477 innodb assertion and crash during alter table to add/drop partition.
  
  The bug was repeated on MyISAM tables, so isn't InnoDB specific.
  Reason of the bug is that partition-related members of TABLE_SHARE
  wasn't properly updated after ALTER command. So if other thread doesn't
  reread frm file, and just uses cached SHARE, it uses wrong data
[1 Jun 2007 15:43] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/27940

ChangeSet@1.2535, 2007-06-01 19:44:09+05:00, holyfoot@mysql.com +3 -0
  Bug #28477 innodb assertion and crash during alter table to add/drop partition.
  
  The bug was repeated on MyISAM tables, so isn't InnoDB specific.
  Reason of the bug is that partition-related members of TABLE_SHARE
  wasn't properly updated after ALTER command. So if other thread doesn't
  reread frm file, and just uses cached SHARE, it uses wrong data
[14 Jun 2007 18:59] Bugs System
Pushed into 5.1.20-beta
[15 Jun 2007 9:24] Jon Stephens
Thank you for your bug report. This issue has been committed to our source repository of that product and will be incorporated into the next release.

If necessary, you can access the source repository and build the latest available version, including the bug fix. More information about accessing the source trees is available at

    http://dev.mysql.com/doc/en/installing-source.html

Documented bugfix in 5.1.20 changelog.
[10 Jul 2009 13:45] Andrii Nikitin
Reopening as this looks not fixed in 5.1.36 with slightly different testcase (original testcase didn't produce stacktrace for me):

delimiter ;

drop procedure if exists `p1`;
delimiter //
create procedure `p1`(`num` int)
begin
  declare `i` int default '0';
  declare continue handler for sqlexception begin end;
  repeat
   drop table if exists `t1`;
   create table `t1` (`a` char(255) primary key) engine=innodb partition by key () partitions 4;
   start transaction;

   select sleep(1);

   alter table `t1` add partition partitions 1;
   alter table `t1` coalesce partition 1;

   select sleep(1);

   set `i`=`i`+1;
   until `i`>=`num` end repeat;

end //

delimiter ;

drop procedure if exists `p2`;
delimiter //

create procedure `p2`(`num` int)
begin
  declare `i` int default '0';
  declare `j` int default '0';
  declare continue handler for sqlexception begin end;

  repeat

   start transaction;
   set `j`=0;
   repeat
     replace into `t1` values (concat(`j`,`i`));
     set `j`=`j`+1;
   until `j`>=1000 end repeat;
   commit;

   set `i`=`i`+1;
   until `i`>=`num` end repeat;

end //

delimiter ;

first connection calls p1(1000000), second calls p2(1000000000).
If mysql started without config file on Windows, it crashes with same stacktrace in 1 minute.
If started with 
--innodb_flush_log_at_trx_commit=0 --innodb_doublewrite=0 --innodb_lock_wait_timeout=1 --innodb_file_per_table
then no crash, just following errors appear in log
090710 15:42:26  InnoDB: Error creating file '.\part\t1#p#p0#tmp#.ibd'.
090710 15:42:26  InnoDB: Operating system error number 80 in a file operation.
* Win32 error code 80: The file exists.

See also bug #45961 which is duplicate of this one.
[10 Jul 2009 13:53] Andrii Nikitin
Stacktrace is little different, probably bug should be reclosed:

InnoDB: Thread 1236 stopped in file G:\mysql-5.1.36-winbuild\mysql-advanced-gpl-5.1.36-build\storage\innobase\include\sync0sync.ic line 115
000000014033D320    mysqld.exe!row_get_mysql_key_number_for_index()[row0mysql.c:1677]
0000000140334DFB    mysqld.exe!ha_innobase::info()[ha_innodb.cc:6224]
0000000140042917    mysqld.exe!ha_partition::info()[ha_partition.cc:4935]
000000014004ACD7    mysqld.exe!handler::get_dup_key()[handler.cc:2954]
000000014004E05F    mysqld.exe!handler::print_error()[handler.cc:2612]
00000001401AD637    mysqld.exe!mysql_change_partitions()[sql_partition.cc:5102]
00000001401B45E7    mysqld.exe!fast_alter_partition_table()[sql_partition.cc:6354]
000000014020B93B    mysqld.exe!mysql_alter_table()[sql_table.cc:6905]
00000001401A4AC4    mysqld.exe!mysql_execute_command()[sql_parse.cc:2861]
000000014013FBE8    mysqld.exe!sp_instr_stmt::exec_core()[sp_head.cc:2908]
0000000140143395    mysqld.exe!sp_lex_keeper::reset_lex_and_exec_core()[sp_head.cc:2735]
0000000140143596    mysqld.exe!sp_instr_stmt::execute()[sp_head.cc:2851]
0000000140144FC5    mysqld.exe!sp_head::execute()[sp_head.cc:1255]
000000014014638F    mysqld.exe!sp_head::execute_procedure()[sp_head.cc:1983]
00000001401A7144    mysqld.exe!mysql_execute_command()[sql_parse.cc:4359]
00000001401A93A6    mysqld.exe!mysql_parse()[sql_parse.cc:5937]
00000001401AA0DA    mysqld.exe!dispatch_command()[sql_parse.cc:1215]
00000001401AB1A7    mysqld.exe!do_command()[sql_parse.cc:854]
000000014024DE37    mysqld.exe!handle_one_connection()[sql_connect.cc:1127]
00000001402BF9A5    mysqld.exe!pthread_start()[my_winthread.c:85]
00000001403D34D7    mysqld.exe!_callthreadstart()[thread.c:295]
00000001403D35A5    mysqld.exe!_threadstart()[thread.c:275]
0000000077A1542D    kernel32.dll!BaseThreadInitThunk()
0000000077B5BE51    ntdll.dll!RtlUserThreadStart()
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0000000003759FE0=alter table `t1` add partition partitions 1
thd->thread_id=2
thd->killed=NOT_KILLED
[18 Jul 2009 3:24] Mikiya Okuno
Hi Andrii,

That stack trace is very much same as bug #45808.