Bug #68311 InnoDB: Failing assertion thr in row0upd.cc on concurrent ALTER, UPDATE, HANDLER
Submitted: 7 Feb 2013 23:21 Modified: 8 Feb 2013 22:02
Reporter: Elena Stepanova Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.6 OS:Linux (Ubuntu 12.04 64-bit)
Assigned to: CPU Architecture:Any

[7 Feb 2013 23:21] Elena Stepanova 
Description:
Version: '5.6.10-debug-log'  
/tmp/master.sock'  port: 19300  Source distribution
2013-02-08 02:08:19 7f3a65e34700  InnoDB: Assertion failure in thread 139888794224384 in file row0upd.cc line 1311
InnoDB: Failing assertion: thr
InnoDB: We intentionally generate a memory trap.

#5  0x00007f3a7b305b8b in __GI_abort () at abort.c:91
#6  0x0000000000c9bd67 in row_upd_changes_ord_field_binary_func (index=0x7f3a30041118, update=0x7f3a30046970, thr=0x0, row=0x0, ext=0x0) at mysql-5.6/storage/innobase/row/row0upd.cc:1311
#7  0x0000000000d17409 in btr_cur_update_in_place (flags=31, cursor=0x7f3a65e2efa0, offsets=0x7f3a3004a760, update=0x7f3a30046970, cmpl_info=0, thr=0x0, trx_id=0, mtr=0x7f3a65e2f0f0) at mysql-5.6/storage/innobase/btr/btr0cur.cc:2000
#8  0x0000000000d179a7 in btr_cur_optimistic_update (flags=31, cursor=0x7f3a65e2efa0, offsets=0x7f3a65e2f088, heap=0x7f3a65e2ef70, update=0x7f3a30046970, cmpl_info=0, thr=0x0, trx_id=0, mtr=0x7f3a65e2f0f0) at mysql-5.6/storage/innobase/btr/btr0cur.cc:2122
#9  0x0000000000d18334 in btr_cur_pessimistic_update (flags=31, cursor=0x7f3a65e2efa0, offsets=0x7f3a65e2f088, offsets_heap=0x7f3a65e2ef70, entry_heap=0x7f3a300465e0, big_rec=0x7f3a65e2f0a0, update=0x7f3a30046970, cmpl_info=0, thr=0x0, trx_id=0, mtr=0x7f3a65e2f0f0) at mysql-5.6/storage/innobase/btr/btr0cur.cc:2380
#10 0x0000000000c7277f in row_log_table_apply_update (thr=0x7f3a3003f120, trx_id_col=1, new_trx_id_col=1, mrec=0x7f3a65cb45ab "\200", offsets=0x7f3a30038290, offsets_heap=0x7f3a3004a660, heap=0x7f3a300465e0, dup=0x7f3a65e2f7f0, trx_id=1608, old_pk=0x7f3a30046658) at mysql-5.6/storage/innobase/row/row0log.cc:1688
#11 0x0000000000c73541 in row_log_table_apply_op (thr=0x7f3a3003f120, trx_id_col=1, new_trx_id_col=1, dup=0x7f3a65e2f7f0, error=0x7f3a65e2f7a8, offsets_heap=0x7f3a3004a660, heap=0x7f3a300465e0, mrec=0x7f3a65cb45ab "\200", mrec_end=0x7f3a65cb84e4 "", offsets=0x7f3a30038290) at mysql-5.6/storage/innobase/row/row0log.cc:2033
#12 0x0000000000c745a5 in row_log_table_apply_ops (thr=0x7f3a3003f120, dup=0x7f3a65e2f7f0) at mysql-5.6/storage/innobase/row/row0log.cc:2326
#13 0x0000000000c749e8 in row_log_table_apply (thr=0x7f3a3003f120, old_table=0x7f3a4403ba28, table=0x7f3a300365f0) at mysql-5.6/storage/innobase/row/row0log.cc:2420
#14 0x0000000000b90436 in ha_innobase::inplace_alter_table (this=0x7f3a30008930, altered_table=0x7f3a300365f0, ha_alter_info=0x7f3a65e2fa50) at mysql-5.6/storage/innobase/handler/handler0alter.cc:3842
#15 0x000000000083e45d in handler::ha_inplace_alter_table (this=0x7f3a30008930, altered_table=0x7f3a300365f0, ha_alter_info=0x7f3a65e2fa50) at mysql-5.6/sql/handler.h:2828
#16 0x0000000000837131 in mysql_inplace_alter_table (thd=0x3c2f8a0, table_list=0x7f3a30004fa8, table=0x7f3a30008050, altered_table=0x7f3a300365f0, ha_alter_info=0x7f3a65e2fa50, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f3a65e31170, alter_ctx=0x7f3a65e2fb50) at mysql-5.6/sql/sql_table.cc:6419
#17 0x000000000083b0ef in mysql_alter_table (thd=0x3c2f8a0, new_db=0x7f3a30005500 "test", new_name=0x0, create_info=0x7f3a65e313b0, table_list=0x7f3a30004fa8, alter_info=0x7f3a65e31490, order_num=0, order=0x0, ignore=false) at mysql-5.6/sql/sql_table.cc:8098
#18 0x000000000097aecf in Sql_cmd_alter_table::execute (this=0x7f3a30005698, thd=0x3c2f8a0) at mysql-5.6/sql/sql_alter.cc:313
#19 0x00000000007ce64e in mysql_execute_command (thd=0x3c2f8a0) at mysql-5.6/sql/sql_parse.cc:4871
#20 0x00000000007d164d in mysql_parse (thd=0x3c2f8a0, rawbuf=0x7f3a30004db0 "ALTER TABLE `table1000_innodb_int_autoinc` ADD COLUMN filler VARCHAR(255) DEFAULT ' filler '", length=92, parser_state=0x7f3a65e33110) at mysql-5.6/sql/sql_parse.cc:6149
#21 0x00000000007c4eda in dispatch_command (command=COM_QUERY, thd=0x3c2f8a0, packet=0x3c335b1 "ALTER TABLE `table1000_innodb_int_autoinc` ADD COLUMN filler VARCHAR(255) DEFAULT ' filler '", packet_length=92) at mysql-5.6/sql/sql_parse.cc:1334
#22 0x00000000007c3fe2 in do_command (thd=0x3c2f8a0) at mysql-5.6/sql/sql_parse.cc:1036
#23 0x000000000078c5a8 in do_handle_one_connection (thd_arg=0x3c2f8a0) at mysql-5.6/sql/sql_connect.cc:969
#24 0x000000000078bfac in handle_one_connection (arg=0x3c2f8a0) at mysql-5.6/sql/sql_connect.cc:885
#25 0x0000000000b3ba86 in pfs_spawn_thread (arg=0x3ab8d30) at mysql-5.6/storage/perfschema/pfs.cc:1853
#26 0x00007f3a7bea4e9a in start_thread (arg=0x7f3a65e34700) at pthread_create.c:308

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f3a30004db0): ALTER TABLE `table1000_innodb_int_autoinc` ADD COLUMN filler VARCHAR(255) DEFAULT ' filler '
Connection ID (thread ID): 7
Status: NOT_KILLED

revision-id: daniel.fischer@oracle.com-20130201133216-o0wf9m4ns9hpdkfo
revno: 4806
branch-nick: mysql-5.6

How to repeat:
# RQG grammar (bug.yy):

query:
	handler_open_close |
	handler_read ;

thread1:
	UPDATE IGNORE _table SET _field = value where ;

thread2: 
	ALTER TABLE _table ADD COLUMN filler VARCHAR(255) DEFAULT ' filler ' |
	ALTER TABLE _table DROP COLUMN filler ;

handler_open_close:
	HANDLER alias1 CLOSE ; HANDLER _table OPEN AS alias1 ;

handler_read:
	HANDLER alias1 READ `PRIMARY` index_op where ;

comp_op:
	= | <= | >= | < | > ;

index_op:
	FIRST | NEXT | PREV | LAST ;

value:
	_digit | _tinyint_unsigned | _varchar(1) ;

where:
	| WHERE _field comp_op value ;

# End of RQG grammar

#########################

# RQG data template (bug.zz):

$tables = {
        rows => [1000],
	engines => [ 'InnoDB' ]
};

$fields = {
        types => [ 'int', 'char(32)' ],
        indexes => [ 'key', 'unique' ],
        null => [undef, 'not null'],
};

$data = {
        numbers => [ 'digit', 'null', undef , 'tinyint_unsigned' ],
        strings => [ 'letter', 'english', 'varchar(3)' ]
}

# End of RQG data template

##############################

RQG command line:

perl runall.pl --grammar=bug.yy --gendata=bug.zz --basedir=mysql-5.6 --queries=100K --duration=600 --threads=3 --mysqld=--innodb-lock-wait-timeout=1 --mysqld=--lock-wait-timeout=1 

# It fails within a minute after start for me, 
# but if it doesn't for you, try to increase the number of threads
[8 Feb 2013 11:22] Erlend Dahl 
I have tried to reproduce the problem, but no luck so far, even with the number of threads increased to 20. 

We will give it a try in another environment.
[8 Feb 2013 11:47] Elena Stepanova 
For a note, my server was built with BUILD/compile-pentium-debug-max-no-ndb.

The machine is Ubuntu 12.04 64-bit (as indicated), in a VM with 4 Gb memory and 2 cores. 

The randgen is from the current tree.

If it doesn't work with the provided grammar/data files, you could also try standard conf/engines/handler.yy and conf/engines/handler.zz, correspondingly. They produce a lot of noise due to unsupported syntax and generally take me longer to reproduce the problem, but maybe it will be different for you.
[8 Feb 2013 12:55] Erlend Dahl 
Thanks, that was very useful. I can reproduce on 5.6.10 but not on recent 5.6.

I will have somebody take a closer look to see what the root cause can be.
[8 Feb 2013 14:22] MySQL Verification Team 
On Windows I couldn't repeat with 5.6.10 source package with the original test and using conf/engines/handler.yy and conf/engines/handler.zz. Windows OS is Windows 7 64-bit 8GB machine.
[8 Feb 2013 22:02] Calvin Sun 
it is a duplicate of an internal bug, which is fixed (will be in 5.6.11).
[8 Feb 2013 22:02] Calvin Sun 
Internal bug#16063835