Bug #45426 UNIV_DEBUG build cause assertion error at CREATE INDEX
Submitted: 10 Jun 2009 9:23 Modified: 19 Jun 2010 0:27
Reporter: Yasufumi Kinoshita Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB Plugin storage engine Severity:S3 (Non-critical)
Version:5.1.34 + 1.0.3 OS:Linux (openSUSE 10.3 (X86-64))
Assigned to: Marko Mäkelä CPU Architecture:Any
Triage: Triaged: D5 (Feature request) / R1 (None/Negligible) / E2 (Low)

[10 Jun 2009 9:23] Yasufumi Kinoshita
Description:
I can reproduce the following situation.
Does this CREATE INDEX generate corrupt index?

090610 18:07:45  InnoDB: Assertion failure in thread 1133021520 in file ../../storage/innobase/include/rem0rec.ic line 1024
InnoDB: Failing assertion: rec_get_n_fields(rec, index) >= rec_offs_n_fields(offsets)
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.

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x43888950 (LWP 22674)]
0x00002b0df4845b45 in raise () from /lib64/libc.so.6
(gdb) up
#1  0x00002b0df48470e0 in abort () from /lib64/libc.so.6
(gdb)
#2  0x000000000076fe0a in rec_offs_make_valid (rec=0x43880c43 "\200\001\212PRICALLYEINGEmY*", index=0x2aaac0009c30, offsets=0x2aaac0005810)
    at ../../storage/innobase/include/rem0rec.ic:1024
1024            ut_ad(rec_get_n_fields(rec, index) >= rec_offs_n_fields(offsets));
Current language:  auto; currently c
(gdb) p rec
$1 = (const rec_t *) 0x43880c43 "\200\001\212PRICALLYEINGEmY*"
(gdb) p *(char *)(rec - 3)
$2 = 11 '\v'
(gdb) p *(char *)(rec - 2)
$3 = 12 '\f'
(gdb) p *(char *)(rec - 1)
$4 = 0 '\0'
(gdb) bt
#0  0x00002b0df4845b45 in raise () from /lib64/libc.so.6
#1  0x00002b0df48470e0 in abort () from /lib64/libc.so.6
#2  0x000000000076fe0a in rec_offs_make_valid (rec=0x43880c43 "\200\001\212PRICALLYEINGEmY*", index=0x2aaac0009c30, offsets=0x2aaac0005810)
    at ../../storage/innobase/include/rem0rec.ic:1024
#3  0x0000000000776f3d in row_merge_read_rec (block=0x2aaabe66f000, buf=0x43880c40, b=0x2aaabe76efeb "\v\f", index=0x2aaac0009c30, fd=43,
    foffs=0x43884c60, mrec=0x43884c58, offsets=0x2aaac0005810) at row/row0merge.c:841
#4  0x0000000000777a12 in row_merge_insert_index_tuples (trx=0x18c9d80, index=0x2aaac0009c30, table=0x19171e0, zip_size=0, fd=43,
    block=0x2aaabe66f000) at row/row0merge.c:1620
#5  0x0000000000777f5b in row_merge_build_indexes (trx=0x18c9d80, old_table=0x19171e0, new_table=0x19171e0, indexes=0x2aaac000aa80,
    n_indexes=1, table=0x2aaac00044e0) at row/row0merge.c:2332
#6  0x00000000007028de in ha_innobase::add_index (this=0x2aaac0001590, table=0x2aaac00044e0, key_info=0x2aaac000dcf0,
    num_of_keys=<value optimized out>) at handler/handler0alter.cc:793
#7  0x000000000067d27a in mysql_alter_table (thd=0x186fac0, new_db=0x18c1ec8 "tpcc", new_name=0x18c1b50 "customer", create_info=0x438870e0,
    table_list=0x18c1b98, alter_info=0x438871c0, order_num=0, order=0x0, ignore=false) at sql_table.cc:6822
#8  0x00000000005a2d98 in mysql_execute_command (thd=0x186fac0) at sql_parse.cc:2741
#9  0x00000000005a6ab4 in mysql_parse (thd=0x186fac0,
    inBuf=0x18c1a40 "CREATE INDEX idx_customer ON customer (c_w_id,c_d_id,c_last,c_first)", length=68, found_semicolon=0x43888070)
    at sql_parse.cc:5902
#10 0x00000000005a769b in dispatch_command (command=COM_QUERY, thd=0x186fac0, packet=<value optimized out>,
    packet_length=<value optimized out>) at sql_parse.cc:1216
#11 0x00000000005a7f59 in do_command (thd=0x186fac0) at sql_parse.cc:857
#12 0x000000000059b563 in handle_one_connection (arg=0x186fac0) at sql_connect.cc:1115
#13 0x00002b0df3d58020 in start_thread () from /lib64/libpthread.so.0
#14 0x00002b0df48d9f8d in clone () from /lib64/libc.so.6
#15 0x0000000000000000 in ?? ()

How to repeat:
Build InnoDB Plugin 1.0.3 with UNIV_DEBUG defined.

Try to create index of data for benchmark.

(e.g.) https://code.launchpad.net/~percona-dev/perconatools/tpcc-mysql

create_table.sql
tpcc_load (1 WH is enough)
add_fkey_idx.sql

Suggested fix:
If it causes corrupt index, to comment out the line
"innobase_hton->alter_table_flags = innobase_alter_table_flags;"
is first-aid for now...
[10 Jun 2009 10:39] Sveta Smirnova
Thank you for the report.

I can not repeat described behavior. Please provide your configuration file and configure options.
[10 Jun 2009 10:41] Sveta Smirnova
test case used

Attachment: bug45426.test (application/octet-stream, text), 609 bytes.

[10 Jun 2009 10:50] Yasufumi Kinoshita
I forgot to attach my.cnf.
my.cnf at the time is
---------------
[mysqld]
gdb
innodb_flush_log_at_trx_commit = 2
innodb_file_per_table = true
innodb_doublewrite = false
innodb_support_xa = false
innodb_buffer_pool_size = 256M
innodb_log_buffer_size = 32M
innodb_log_file_size = 64M
datadir = /opt/mysql-5.1.29_p/data
----------------
[10 Jun 2009 14:23] Sveta Smirnova
Thank you for the feedback.

I still can not repeat described behavior. Please provide configure options you used when compile mysqld and plugin. Please also check with test case I used if this is enough or table should contain some data.
[11 Jun 2009 0:26] Yasufumi Kinoshita
Sure, the table needs data.
Please follow the procedure..
==========
bzr branch lp:~percona-dev/perconatools/tpcc-mysql
cd tpcc-mysql/src
(edit mysql_config path of Makefile)
make
cd ..
mysql -uroot
mysql> create database tpcc;
mysql> GRANT all privileges ON tpcc.* TO tpcc@localhost IDENTIFIED BY 'tpcc';
mysql> quit
mysql tpcc -utpcc -ptpcc < create_table.sql
./tpcc_load localhost tpcc tpcc tpcc 1
mysql tpcc -utpcc -ptpcc < add_fkey_idx.sql
==========

And, build option is,,,
(overwrite storage/innobase with innodb_plugin-1.0.3)
(add "#define UNIV_DEBUG" to storage/innobase/include/univ.i)
==========
export CFLAGS="-O2 -g -fmessage-length=0 -D_FORTIFY_SOURCE=2"
export CXXFLAGS="-O2 -g -fmessage-length=0 -D_FORTIFY_SOURCE=2"

./configure \
            --disable-shared \
            --with-server-suffix='-yasufumi_test' \
            --without-embedded-server \
            --with-innodb \
            --without-plugin-maria \
            --with-partition \
            --with-csv-storage-engine \
            --with-archive-storage-engine \
            --with-blackhole-storage-engine \
            --with-federated-storage-engine \
            --without-bench \
            --with-zlib-dir=bundled \
            --with-big-tables \
            --enable-assembler \
            --enable-local-infile \
            --with-mysqld-user=mysql \
            --with-unix-socket-path=/opt/mysql-5.1.29_p/mysql.sock \
            --with-pic \
            --prefix=/opt/mysql-5.1.29_p \
            --with-extra-charsets=complex \
            --exec-prefix=/opt/mysql-5.1.29_p \
            --libexecdir=/opt/mysql-5.1.29_p/bin \
            --libdir=/opt/mysql-5.1.29_p/lib64 \
            --sysconfdir=/opt/mysql-5.1.29_p/etc \
            --datadir=/opt/mysql-5.1.29_p/share \
            --localstatedir=/opt/mysql-5.1.29_p/data \
            --infodir=/opt/mysql-5.1.29_p/share/info \
            --includedir=/opt/mysql-5.1.29_p/include \
            --mandir=/opt/mysql-5.1.29_p/share/man \
            --enable-thread-safe-client \
            --with-readline \
; make -j2
==========
[11 Jun 2009 8:16] Sveta Smirnova
Thank you for the feedback.

Verified as described in last comment: compiled with options indicated on 64-bit Linux, tun described sequence of actions, used specified options and innodb_file_format = barracuda. Could not reduce test - doesn't fail.
[17 Jun 2009 12:39] Marko Mäkelä
This looks like bogus debug code, not a critical error. InnoDB is not normally built with UNIV_DEBUG.

In the merge sort buffer, the records are stored in a format that resembles ROW_FORMAT=COMPACT, but without the REC_N_NEW_EXTRA_BYTES. There is a comment that explains this in the beginning of rec_init_offsets_comp_ordinary().

The rec_offs_make_valid() call in row_merge_read_rec() should be replaced with explicit assignments, like in rec_init_offsets_comp_ordinary():

Index: row/row0merge.c
===================================================================
--- row/row0merge.c	(revision 5342)
+++ row/row0merge.c	(working copy)
@@ -849,7 +849,13 @@ err_exit:
 	avail_size = block[1] - b;
 	memcpy(*buf, b, avail_size);
 	*mrec = *buf + extra_size;
-	rec_offs_make_valid(*mrec, index, offsets);
+#ifdef UNIV_DEBUG
+	/* We cannot invoke rec_offs_make_valid() here, because it can hold
+	that extra != REC_N_NEW_EXTRA_BYTES.  Similarly, rec_offs_validate()
+	will fail in that case, because it invokes rec_get_status(). */
+	offsets[2] = (ulint) *mrec;
+	offsets[3] = (ulint) index;
+#endif /* UNIV_DEBUG */
 
 	if (!row_merge_read(fd, ++(*foffs), block)) {
 
By the way, the tpcc_load program does a double-free when it fails to connect the server. This fixed it, but ultimately I had to create /var/run/mysqld and a socket file:

@@ -267,6 +268,7 @@
 	exit(0);
 Error_SqlCall_close:
 	mysql_close(mysql);
+	exit(1);
 Error_SqlCall:
 	Error(0);
 }
[17 Jun 2009 13:04] Marko Mäkelä
The fix will be in InnoDB Plugin 1.0.4.
[12 Aug 2009 13:34] Calvin Sun
Fixed in 1.0.4.
[5 May 2010 15:08] Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[6 May 2010 17:47] Paul Dubois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.
[28 May 2010 6:09] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)
[28 May 2010 6:37] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[28 May 2010 7:05] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[30 May 2010 0:14] Paul Dubois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.
[15 Jun 2010 8:11] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100615080459-smuswd9ooeywcxuc) (version source revid:mmakela@bk-internal.mysql.com-20100415070122-1nxji8ym4mao13ao) (merge vers: 5.1.47) (pib:16)
[15 Jun 2010 8:26] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100615080558-cw01bzdqr1bdmmec) (version source revid:mmakela@bk-internal.mysql.com-20100415070122-1nxji8ym4mao13ao) (pib:16)
[17 Jun 2010 12:14] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:01] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:42] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)