Bug #77108 InnoDB: Failing assertion: index == cursor->index in btr0sea.cc line 1782
Submitted: 21 May 2015 4:52 Modified: 21 May 2015 6:29
Reporter: Ramesh Sivaraman (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: DML Severity:S3 (Non-critical)
Version:5.6.23, 5.6.26 OS:Linux (CentOS 7)
Assigned to: CPU Architecture:Any
Tags: debug

[21 May 2015 4:52] Ramesh Sivaraman
Description:
2015-05-21 00:48:04 7f2ccd2bf700  InnoDB: Assertion failure in thread 139830397499136 in file btr0sea.cc line 1782
InnoDB: Failing assertion: index == cursor->index
InnoDB: We intentionally generate a memory trap.

GDB info

#0  0x00007ffb9432f771 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000000a980a6 in my_write_core (sig=6) at /sda/mysql-server-5.6/mysys/stacktrace.c:422
#2  0x00000000007277f0 in handle_fatal_signal (sig=6) at /sda/mysql-server-5.6/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007ffb9313b5d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5  0x00007ffb9313ccc8 in __GI_abort () at abort.c:90
#6  0x0000000000d409a1 in btr_search_update_hash_on_insert (cursor=0x7ffb948e50a0) at /sda/mysql-server-5.6/storage/innobase/btr/btr0sea.cc:1733
#7  0x0000000000d2a586 in btr_cur_optimistic_insert (flags=0, cursor=0x7ffb948e50a0, offsets=0x7ffb948e5610, heap=0x7ffb948e5600, entry=0x7ffb7586c0f8, rec=0x7ffb948e55f8, big_rec=0x7ffb948e5608, n_ext=0, thr=0x7ffb75948350, mtr=0x7ffb948e5120) at /sda/mysql-server-5.6/storage/innobase/btr/btr0cur.cc:1452
#8  0x0000000000c591ad in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7ffb7586caf8, n_uniq=0, entry=0x7ffb7586c0f8, n_ext=0, thr=0x7ffb75948350) at /sda/mysql-server-5.6/storage/innobase/row/row0ins.cc:2473
#9  0x0000000000c5a095 in row_ins_clust_index_entry (index=0x7ffb7586caf8, entry=0x7ffb7586c0f8, thr=0x7ffb75948350, n_ext=0) at /sda/mysql-server-5.6/storage/innobase/row/row0ins.cc:2867
#10 0x0000000000c5a395 in row_ins_index_entry (index=0x7ffb7586caf8, entry=0x7ffb7586c0f8, thr=0x7ffb75948350) at /sda/mysql-server-5.6/storage/innobase/row/row0ins.cc:2965
#11 0x0000000000c5a676 in row_ins_index_entry_step (node=0x7ffb75948130, thr=0x7ffb75948350) at /sda/mysql-server-5.6/storage/innobase/row/row0ins.cc:3042
#12 0x0000000000c5a97a in row_ins (node=0x7ffb75948130, thr=0x7ffb75948350) at /sda/mysql-server-5.6/storage/innobase/row/row0ins.cc:3182
#13 0x0000000000c5acff in row_ins_step (thr=0x7ffb75948350) at /sda/mysql-server-5.6/storage/innobase/row/row0ins.cc:3307
#14 0x0000000000c71cc2 in row_insert_for_mysql (mysql_rec=0x7ffb75897ed8 "\377", prebuilt=0x7ffb75947c78) at /sda/mysql-server-5.6/storage/innobase/row/row0mysql.cc:1367
#15 0x0000000000b7e1ce in ha_innobase::write_row (this=0x7ffb75897c10, record=0x7ffb75897ed8 "\377") at /sda/mysql-server-5.6/storage/innobase/handler/ha_innodb.cc:6645
#16 0x0000000000645c52 in handler::ha_write_row (this=0x7ffb75897c10, buf=0x7ffb75897ed8 "\377") at /sda/mysql-server-5.6/sql/handler.cc:7273
#17 0x00000000007b55d0 in write_record (thd=0x7ffb83bee000, table=0x7ffb75946e00, info=0x7ffb948e5b00, update=0x7ffb948e5b80) at /sda/mysql-server-5.6/sql/sql_insert.cc:1921
#18 0x00000000007b3461 in mysql_insert (thd=0x7ffb83bee000, table_list=0x7ffb7581f118, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /sda/mysql-server-5.6/sql/sql_insert.cc:1072
#19 0x00000000007d5704 in mysql_execute_command (thd=0x7ffb83bee000) at /sda/mysql-server-5.6/sql/sql_parse.cc:3443
#20 0x00000000007dd54a in mysql_parse (thd=0x7ffb83bee000, rawbuf=0x7ffb7581f010 "insert INTO t1 values(date_format(0,'%a'))", length=42, parser_state=0x7ffb948e6e70) at /sda/mysql-server-5.6/sql/sql_parse.cc:6357
#21 0x00000000007d06bc in dispatch_command (command=COM_QUERY, thd=0x7ffb83bee000, packet=0x7ffb7cfe1001 "insert INTO t1 values(date_format(0,'%a'))", packet_length=42) at /sda/mysql-server-5.6/sql/sql_parse.cc:1332
#22 0x00000000007cf7ab in do_command (thd=0x7ffb83bee000) at /sda/mysql-server-5.6/sql/sql_parse.cc:1034
#23 0x0000000000797b3d in do_handle_one_connection (thd_arg=0x7ffb83bee000) at /sda/mysql-server-5.6/sql/sql_connect.cc:982
#24 0x0000000000797626 in handle_one_connection (arg=0x7ffb83bee000) at /sda/mysql-server-5.6/sql/sql_connect.cc:898
#25 0x0000000000b5d7f0 in pfs_spawn_thread (arg=0x7ffb8ebfe600) at /sda/mysql-server-5.6/storage/perfschema/pfs.cc:1860
#26 0x00007ffb9432adf5 in start_thread (arg=0x7ffb948e8700) at pthread_create.c:308
#27 0x00007ffb931fc1ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

How to repeat:
The attached tarball gives the testcase as an exact match of our system, including some handy utilities

$ vi {epoch}_mybase # Update base path in this file (the only change
required!). For non-binary distribution please update SOURCE_DIR location also.
$ ./{epoch}_init # Initializes the data dir
$ ./{epoch}_start # Starts mysqld
$ ./{epoch}_cl # To check mysqld is up
$ ./{epoch}_run # Run the testcase with pquery binary(produces
output)
$ vi /dev/shm/{epoch}/error.log.out # Verify the error log
$ ./{epoch}_gdb # Brings you to a gdb prompt attached to correct
mysqld
& generated core
$ ./{epoch}_parse_core # Create {epoch}_STD.gdb and {epoch}_FULL.gdb;
standard and full var gdb stack traces
etc.
[21 May 2015 4:53] Ramesh Sivaraman
Testcase bundle

Attachment: 1430249974_bug_bundle.tar.gz (application/gzip, text), 1014.50 KiB.

[21 May 2015 6:29] Umesh Shastry
Hello Ramesh,

Thank you for the report and test case.
Observed that only debug builds are affected.

Thanks,
Umesh
[21 May 2015 6:30] Umesh Shastry
// 5.6.26 - only debug build affected

scripts/mysql_install_db --basedir=/export/umesh/server/binaries/mysql-5.6.26 --datadir=/export/umesh/server/binaries/mysql-5.6.26/77108
bin/mysqld-debug  --no-defaults --basedir=/export/umesh/server/binaries/mysql-5.6.26 --datadir=/export/umesh/server/binaries/mysql-5.6.26/77108 --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.6.26/77108/log.err --innodb_file_per_table=1 --innodb_flush_method=O_DIRECT --log-bin=binlog --binlog_format=MIXED --event-scheduler=ON --maximum-bulk_insert_buffer_size=1M --maximum-join_buffer_size=1M --maximum-max_heap_table_size=1M --maximum-max_join_size=1M --maximum-myisam_max_sort_file_size=1M --maximum-myisam_mmap_size=1M --maximum-myisam_sort_buffer_size=1M --maximum-optimizer_trace_max_mem_size=1M --maximum-preload_buffer_size=1M --maximum-query_alloc_block_size=1M --maximum-query_prealloc_size=1M --maximum-range_alloc_block_size=1M --maximum-read_buffer_size=1M --maximum-read_rnd_buffer_size=1M --maximum-sort_buffer_size=1M --maximum-tmp_table_size=1M --maximum-transaction_alloc_block_size=1M --maximum-transaction_prealloc_size=1M --log-output=none --sql_mode=ONLY_FULL_GROUP_BY 2>&1 &

-- build used

commit: 52ccefd205a2a9263a5429dfca1a183f19caf70e
date: 2015-05-15 11:58:55 +0300
build-date: 2015-05-16 09:00:52 +0200
short: 52ccefd
branch: mysql-5.6

MySQL source 5.6.26

// Exatrct from error log

2015-05-21 08:07:34 26408 [Note] bin/mysqld-debug: ready for connections.
Version: '5.6.26-enterprise-commercial-advanced-debug-log'  socket: '/tmp/mysql_ushastry.sock'  port: 15000  MySQL Enterprise Server - Advanced Edition Debug (Commercial)
2015-05-21 08:07:34 26408 [Note] Event Scheduler: scheduler thread started with id 1
2015-05-21 08:07:41 7f0490a0b700  InnoDB: Warning: cannot find a free slot for an undo log. Do you have too
InnoDB: many active transactions running concurrently?
2015-05-21 08:07:41 7f0490a0b700InnoDB: unknown error code 47 while dropping table:`tmp`.`#sql6728_2_0`.
2015-05-21 08:07:41 26408 [Warning] Could not remove temporary table: '/tmp/#sql6728_2_0', error: 2
2015-05-21 08:07:41 7f0490a0b700  InnoDB: Assertion failure in thread 139657583048448 in file btr0sea.cc line 1733
InnoDB: Failing assertion: index == cursor->index

(gdb) bt
#0  0x00007f04bb1b1771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000ae21cf in my_write_core (sig=6) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/mysys/stacktrace.c:422
#2  0x000000000074643a in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007f04b9db75c9 in raise () from /lib64/libc.so.6
#5  0x00007f04b9db8cd8 in abort () from /lib64/libc.so.6
#6  0x0000000000caf75a in btr_search_update_hash_on_insert (cursor=0x7f0490a084c0) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/btr/btr0sea.cc:1733
#7  0x0000000000ca2e5a in btr_cur_optimistic_insert (flags=0, cursor=0x7f0490a084c0, offsets=0x7f0490a08560, heap=0x7f0490a08550, entry=0x7f0460019938, rec=0x7f0490a08548,
    big_rec=0x7f0490a08558, n_ext=0, thr=0x7f0460021570, mtr=0x7f0490a07ff0) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/btr/btr0cur.cc:1452
#8  0x0000000000bd13d9 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7f04600206d8, n_uniq=0, entry=0x7f0460019938, n_ext=0, thr=0x7f0460021570)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0ins.cc:2473
#9  0x0000000000bd4a06 in row_ins_clust_index_entry (index=0x7f04600206d8, entry=0x7f0460019938, thr=0x7f0460021570, n_ext=0)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0ins.cc:2867
#10 0x0000000000bd4b52 in row_ins_index_entry (index=0x7f04600206d8, entry=0x7f0460019938, thr=0x7f0460021570)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0ins.cc:2965
#11 0x0000000000bd4c30 in row_ins_index_entry_step (node=0x7f0460021350, thr=0x7f0460021570)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0ins.cc:3042
#12 0x0000000000bd4d83 in row_ins (node=0x7f0460021350, thr=0x7f0460021570) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0ins.cc:3182
#13 0x0000000000bd50f6 in row_ins_step (thr=0x7f0460021570) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0ins.cc:3307
#14 0x0000000000bf273f in row_insert_for_mysql (mysql_rec=0x7f0460018018 "\377", prebuilt=0x7f0460020e98)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/row/row0mysql.cc:1363
#15 0x0000000000b0f0f4 in ha_innobase::write_row (this=0x7f0460017d50, record=0x7f0460018018 "\377")
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/innobase/handler/ha_innodb.cc:6633
#16 0x000000000064d537 in handler::ha_write_row (this=0x7f0460017d50, buf=0x7f0460018018 "\377") at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/handler.cc:7273
#17 0x00000000007da584 in write_record (thd=0x2f69cc0, table=0x7f046001f2c0, info=0x7f0490a08c00, update=0x7f0490a08b80)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_insert.cc:1921
#18 0x00000000007e003d in mysql_insert (thd=0x2f69cc0, table_list=0x7f04600050d8, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_insert.cc:1072
#19 0x00000000007fd569 in mysql_execute_command (thd=0x2f69cc0) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_parse.cc:3450
#20 0x0000000000802a66 in mysql_parse (thd=0x2f69cc0, rawbuf=0x7f0460004fd0 "insert INTO t1 values(date_format(0,'%a'))", length=42, parser_state=0x7f0490a0a700)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_parse.cc:6386
#21 0x000000000080468a in dispatch_command (command=COM_QUERY, thd=0x2f69cc0, packet=0x304f1f1 "insert INTO t1 values(date_format(0,'%a'))", packet_length=42)
    at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_parse.cc:1340
#22 0x0000000000805f16 in do_command (thd=0x2f69cc0) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_parse.cc:1037
#23 0x00000000007bb949 in do_handle_one_connection (thd_arg=0x2f69cc0) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_connect.cc:982
#24 0x00000000007bba0f in handle_one_connection (arg=0x2f69cc0) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/sql/sql_connect.cc:898
#25 0x0000000000daf210 in pfs_spawn_thread (arg=0x2fbfa70) at /export/home/pb2/build/sb_0-15307164-1431760457.15/mysqlcom-pro-5.6.26/storage/perfschema/pfs.cc:1860
#26 0x00007f04bb1acdf3 in start_thread () from /lib64/libpthread.so.0
#27 0x00007f04b9e7847d in clone () from /lib64/libc.so.6
[21 May 2015 6:35] Umesh Shastry
// Didn't notice any issue with 5.7.8 debug builds.