Fake changes assertion fail in row_ins_clust_index_entry_by_modify() | btr_store_big_rec_extern_fields ()

Bug #1188168 reported by Laurynas Biveinis
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
High
Laurynas Biveinis
5.1
Fix Released
High
Laurynas Biveinis
5.5
Fix Released
High
Laurynas Biveinis
5.6
Fix Released
High
Laurynas Biveinis

Bug Description

Intermittently seen on Facebook's testcase: https://github.com/facebook/mysql-5.6/blob/mysql-5.6.11/mysql-test/t/percona_innodb_fake_changes_bugs4.test

Thread 1 (Thread 0x7f74f04e0700 (LWP 4377)):
#0 0x00007f74fcdc9f2c in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:62
#1 0x0000000000abbab1 in my_write_core (sig=6) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/mysys/stacktrace.c:422
#2 0x000000000072ccdd in handle_fatal_signal (sig=6) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/signal_handler.cc:251
#3 <signal handler called>
#4 0x00007f74fc20e037 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5 0x00007f74fc211698 in __GI_abort () at abort.c:90
#6 0x0000000000c8dd18 in row_ins_clust_index_entry_by_modify (flags=0, mode=37, cursor=0x7f74f04dca30, offsets=0x7f74f04dc9f0, offsets_heap=0x7f74f04dca00, heap=0x7f74d80408d0, big_rec=0x7f74f04dc9f8, entry=0x7f74d80c8838, thr=0x7f74d80429d8, mtr=0x7f74f04dcab0) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:363
#7 0x0000000000c920e9 in row_ins_clust_index_entry_low (flags=0, mode=37, index=0x7f74d80b4698, n_uniq=1, entry=0x7f74d80c8838, n_ext=0, thr=0x7f74d80429d8) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:2407
#8 0x0000000000c93494 in row_ins_clust_index_entry (index=0x7f74d80b4698, entry=0x7f74d80c8838, thr=0x7f74d80429d8, n_ext=0) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:2887
#9 0x0000000000c93752 in row_ins_index_entry (index=0x7f74d80b4698, entry=0x7f74d80c8838, thr=0x7f74d80429d8) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:2981
#10 0x0000000000c93a3b in row_ins_index_entry_step (node=0x7f74d8042798, thr=0x7f74d80429d8) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:3058
#11 0x0000000000c93d49 in row_ins (node=0x7f74d8042798, thr=0x7f74d80429d8) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:3198
#12 0x0000000000c940d9 in row_ins_step (thr=0x7f74d80429d8) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0ins.cc:3323
#13 0x0000000000cab445 in row_insert_for_mysql (mysql_rec=0x7f74d8043d80 "\376\004", prebuilt=0x7f74d80422c8) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/row/row0mysql.cc:1312
#14 0x0000000000bab3d8 in ha_innobase::write_row (this=0x7f74d8037b30, record=0x7f74d8043d80 "\376\004") at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/innobase/handler/ha_innodb.cc:6929
#15 0x0000000000646f61 in handler::ha_write_row (this=0x7f74d8037b30, buf=0x7f74d8043d80 "\376\004") at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/handler.cc:7414
#16 0x00000000007c03f1 in write_record (thd=0x2943400, table=0x7f74d806b3a0, info=0x7f74f04dd4f0, update=0x7f74f04dd570) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_insert.cc:1905
#17 0x00000000007be026 in mysql_insert (thd=0x2943400, table_list=0x7f74d8005120, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_insert.cc:1054
#18 0x00000000007e0c6e in mysql_execute_command (thd=0x2943400) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_parse.cc:3634
#19 0x00000000007e88f3 in mysql_parse (thd=0x2943400, rawbuf=0x7f74d8005010 "INSERT INTO t1 VALUES (4, lpad('a',12000,'b'))", length=46, parser_state=0x7f74f04dee50) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_parse.cc:6451
#20 0x00000000007db536 in dispatch_command (command=COM_QUERY, thd=0x2943400, packet=0x2a206a1 "INSERT INTO t1 VALUES (4, lpad('a',12000,'b'))", packet_length=46) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_parse.cc:1376
#21 0x00000000007da531 in do_command (thd=0x2943400) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_parse.cc:1051
#22 0x00000000007a1fde in do_handle_one_connection (thd_arg=0x2943400) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_connect.cc:1615
#23 0x00000000007a1aac in handle_one_connection (arg=0x2943400) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/sql/sql_connect.cc:1526
#24 0x0000000000b9237e in pfs_spawn_thread (arg=0x2a1a460) at /home/laurynas/percona/src/fb-fake-changes/5.6/Percona-Server/storage/perfschema/pfs.cc:1853
#25 0x00007f74fcdc4f8e in start_thread (arg=0x7f74f04e0700) at pthread_create.c:311
#26 0x00007f74fc2d0e1d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Related branches

tags: added: fake-changes xtradb
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

Reduced testcase (crashes ~1 run in ~4)

source include/have_innodb.inc;
source include/have_debug.inc;
CREATE TABLE t1(id INT NOT NULL PRIMARY KEY, data text) Engine=InnoDB;

INSERT INTO t1 VALUES(1, '');
INSERT INTO t1 VALUES(2, '');
INSERT INTO t1 VALUES(3, '');
INSERT INTO t1 VALUES(4, '');

DELETE FROM t1 WHERE id = 4;
SET innodb_fake_changes=1;
--error ER_ERROR_DURING_COMMIT
INSERT INTO t1 VALUES (4, lpad('a',12000,'b'));
SET innodb_fake_changes=0;
SELECT * FROM t1;
DROP TABLE t1;

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :
Download full text (32.9 KiB)

Crashes 5.5 too. My guess about this being 5.6 port regression (bug 1188172) was wrong.

130711 14:34:14 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
130711 14:34:14 InnoDB: The InnoDB memory heap is disabled
130711 14:34:14 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130711 14:34:14 InnoDB: Compressed tables use zlib 1.2.7
130711 14:34:14 InnoDB: Initializing buffer pool, size = 32.0M
130711 14:34:14 InnoDB: Completed initialization of buffer pool
130711 14:34:14 InnoDB: highest supported file format is Barracuda.
130711 14:34:14 InnoDB: Waiting for the background threads to start
130711 14:34:15 Percona XtraDB (http://www.percona.com) 5.5.31-29.3 started; log sequence number 1597945
130711 14:34:15 [Note] Event Scheduler: Loaded 0 events
130711 14:34:15 [Note] /home/laurynas/percona/src/fake-changes-from-fb/5.5/obj-debug/sql/mysqld: ready for connections.
Version: '5.5.31-debug-log' socket: '/home/laurynas/percona/src/fake-changes-from-fb/5.5/obj-debug/mysql-test/var/tmp/mysqld.1.sock' port: 13001 Source distribution
InnoDB: DEBUG: update_statistics for test/t1.
InnoDB: DEBUG: update_statistics for test/t1.
InnoDB: DEBUG: update_statistics for test/t1.
130711 14:34:15 InnoDB: Assertion failure in thread 140511718549248 in file btr0cur.c line 4388
InnoDB: Failing assertion: rec_offs_any_extern(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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
11:34:15 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61693 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x33b1390
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...
stack_bottom = 7fcb6f121e00 thread_stack 0x40000
/home/laurynas/percona/src/fake-changes-from-fb/5.5/obj-debug/sql/mysqld(my_print_stacktrace+0x38)[0x8ff98e]
/home/laurynas/percona/src/fake-changes-from-fb/5.5/obj-debug/sql/mysqld(handle_fatal_signal+0x42d)[0x781885]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xfbd0)[0x7fcb7b242bd0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7fcb7a45d037]
/lib/x86_64-linu...

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :
Download full text (25.3 KiB)

Crashes 5.1 as well:

--source include/have_innodb_plugin.inc

--disable_warnings
DROP TABLE IF EXISTS t1;
--enable_warnings

CREATE TABLE t1(id INT NOT NULL PRIMARY KEY, data TEXT) ENGINE=InnoDB;

INSERT INTO t1 VALUES(1, '');
INSERT INTO t1 VALUES(2, '');
INSERT INTO t1 VALUES(3, '');
INSERT INTO t1 VALUES(4, '');

DELETE FROM t1 WHERE id = 4;

SET innodb_fake_changes=1;

--error ER_ERROR_DURING_COMMIT
INSERT INTO t1 VALUES (4, LPAD('a', 12000, 'b'));

SET innodb_fake_changes=0;

DROP TABLE t1;

130711 14:48:49 InnoDB: Assertion failure in thread 140660380555008 in file btr/btr0cur.c line 4277
InnoDB: Failing assertion: rec_offs_any_extern(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-innodb-recovery.html
InnoDB: about forcing recovery.
11:48:49 UTC - 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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60723 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x1f5def8
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...
stack_bottom = 7fee0c044e78 thread_stack 0x40000
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld(my_print_stacktrace+0x38)[0xa888d7]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld(handle_fatal_signal+0x3a9)[0x7ce305]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xfbd0)[0x7fee0f3b0bd0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7fee0e6b7037]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7fee0e6ba698]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x98f840]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x930a3c]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x931025]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x931320]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x9315ea]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x9318bb]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/mysqld[0x938e3f]
/home/laurynas/percona/src/percona-server/5.1/Percona-Server/sql/m...

summary: - Fake changes assertion fail in row_ins_clust_index_entry_by_modify()
+ Fake changes assertion fail in row_ins_clust_index_entry_by_modify() |
+ btr_store_big_rec_extern_fields ()
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-673

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.