| Bug #55543 | InnoDB Plugin: Signal 6: Assertion failure in file fil/fil0fil.c line 4306 | ||
|---|---|---|---|
| Submitted: | 26 Jul 2010 2:58 | Modified: | 27 Jan 2011 19:13 |
| Reporter: | Roel Van de Paar | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: InnoDB Plugin storage engine | Severity: | S1 (Critical) |
| Version: | 5.1.49, 5.5, 5.5.6rc | OS: | Linux |
| Assigned to: | Sunny Bains | CPU Architecture: | Any |
[26 Jul 2010 2:58]
Roel Van de Paar
[26 Jul 2010 3:14]
Roel Van de Paar
Verifying based on the fact that I have been able to reproduce it several times, and also this: bug #49893
[26 Jul 2010 4:23]
Roel Van de Paar
Attachment: crash1.txt (text/plain), 6.45 KiB.
[26 Jul 2010 4:24]
Roel Van de Paar
Attachment: crash2.txt (text/plain), 81.50 KiB.
[26 Jul 2010 4:24]
Roel Van de Paar
Files needed to reproduce
Attachment: crash3.txt (text/plain), 28.68 KiB.
[26 Jul 2010 4:25]
Roel Van de Paar
s/Files needed to reproduce//
[26 Jul 2010 4:26]
Roel Van de Paar
See bug #55542
[26 Jul 2010 7:08]
Calvin Sun
Likely caused by the mismatch of data files and log files. Which data files mysqld1 uses? which ones mysqld2 uses?
[26 Jul 2010 10:01]
Roel Van de Paar
No, this is not the case: I was able to reproduce this using a clean setup: no running mysqld's, directories deleted (see start of script above: rm -R /tmp/51/ and rm -R /tmp/52/) and then start script. Had to try a few times (~3-5) to get it to crash, but then it did: ============= roel@roel-ubuntu-vm:/randgen/new_testing/5$ kill -9 `pidof mysqld` roel@roel-ubuntu-vm:/randgen/new_testing/5$ ps -A | grep -v grep | grep mysqld roel@roel-ubuntu-vm:/randgen/new_testing/5$ ./5 > 5out2.txt rm: cannot remove `./51.log': No such file or directory rm: cannot remove `./52.log': No such file or directory "/randgen/randgen/" is not a core dump: Is a directory No stack. /randgen/randgen/backtrace.gdb:20: Error in sourced command file: No registers. "/randgen/randgen/" is not a core dump: Is a directory /randgen/randgen/backtrace-all.gdb:19: Error in sourced command file: No registers. warning: Can't read pathname for load map: Input/output error. 4319 mysqld.cc: No such file or directory. warning: Can't read pathname for load map: Input/output error. roel@roel-ubuntu-vm:/randgen/new_testing/5$ ls -l /tmp/51/master-data/ total 28688 -rw-rw---- 1 roel roel 18874368 2010-07-26 19:35 ibdata1 -rw-rw---- 1 roel roel 5242880 2010-07-26 19:35 ib_logfile0 -rw-rw---- 1 roel roel 5242880 2010-07-26 19:35 ib_logfile1 -rw-rw---- 1 roel roel 5349 2010-07-26 19:36 innodb_status.21149 drwxr-xr-x 2 roel roel 4096 2010-07-26 19:35 mysql drwxr-xr-x 2 roel roel 4096 2010-07-26 19:35 test roel@roel-ubuntu-vm:/randgen/new_testing/5$ ls -l /tmp/52/master-data/ total 59388 -rw------- 1 roel roel 281481216 2010-07-26 19:35 core -rw-rw---- 1 roel roel 18874368 2010-07-26 19:35 ibdata1 -rw-rw---- 1 roel roel 5242880 2010-07-26 19:35 ib_logfile0 -rw-rw---- 1 roel roel 5242880 2010-07-26 19:35 ib_logfile1 -rw-rw---- 1 roel roel 0 2010-07-26 19:35 innodb_status.21177 drwxr-xr-x 2 roel roel 4096 2010-07-26 19:35 mysql drwxr-xr-x 2 roel roel 4096 2010-07-26 19:35 test roel@roel-ubuntu-vm:/randgen/new_testing/5$ ps -A | grep -v grep | grep mysqld 21149 pts/1 00:00:01 mysqld <---- Only one mysqld running, the other one crashed. =============
[26 Jul 2010 10:04]
Roel Van de Paar
This was using --queries=5000 --threads=10
Attachment: 5out2.txt (text/plain), 97.97 KiB.
[26 Jul 2010 10:09]
MySQL Verification Team
so, purge thread crashes in the background. its confusing why this testcase needs two instances of mysqld?
[26 Jul 2010 10:18]
Roel Van de Paar
Core file from earlier crash
Attachment: core_bug_55543_1.tar.gz (application/x-gzip, text), 281.75 KiB.
[26 Jul 2010 15:05]
Calvin Sun
Thanks for the additional info. Please try with only one instance of mysqld. Also, where we can get the randgen you are using?
[26 Jul 2010 15:15]
Valeriy Kravchuk
Random query generator is available at https://launchpad.net/randgen. See http://forge.mysql.com/wiki/RQG also.
[27 Jul 2010 1:01]
Roel Van de Paar
Only took one attempt to get it to crash with one server. ============== roel@roel-ubuntu-vm:/randgen/new_testing/5$ cat 5 kill -9 `pidof mysqld` cd /randgen/randgen rm -R /tmp/bug55543/ rm ./bug55543.log perl ./runall.pl \ --basedir=/mysql/mysql-5.1.49-linux-i686-glibc23/ \ --vardir=/tmp/bug55543/ \ --mysqld=--log-output=none \ --mysqld=--log_error=/randgen/new_testing/5/bug55543.log \ --mysqld=--ignore-builtin-innodb \ --mysqld=--plugin-load=innodb=ha_innodb_plugin.so:innodb_trx=ha_innodb_plugin.so:innodb_locks=ha_innodb_plugin.so:innodb_cmp=ha_innodb_plugin.so:innodb_cmp_reset=ha_innodb_plugin.so:innodb_cmpmem=ha_innodb_plugin.so:innodb_cmpmem_reset=ha_innodb_plugin.so \ --mysqld=--plugin-dir=/mysql/mysql-5.1.49-linux-i686-glibc23/lib/plugin/ \ --gendata=/randgen/new_testing/5/5.zz \ --grammar=/randgen/new_testing/5/5.yy \ --queries=5000 \ --threads=10 \ --Validators=ResultsetComparator,MarkErrorLog,AbortOnSyntaxError cd /randgen/new_testing/5/ ==============
[27 Jul 2010 1:04]
Roel Van de Paar
Log of one server only crash
Attachment: bug55543_1.log (application/octet-stream, text), 6.26 KiB.
[27 Jul 2010 1:05]
Roel Van de Paar
Attachment: screencapture_bug_55543_single_server_only.txt (text/plain), 37.75 KiB.
[27 Jul 2010 1:06]
Roel Van de Paar
(All testing for this bug was done using latest bzr pull of randgen)
[3 Aug 2010 10:48]
Marko Mäkelä
Bug #55284 is a possible duplicate of this.
[3 Aug 2010 12:03]
Marko Mäkelä
Sorry, it could have been a wrong alert about the BLOB leak. I ran this under gdb:
CREATE TABLE t(a INT PRIMARY KEY,b TEXT)ENGINE=InnoDB;
INSERT INTO t VALUES(1,repeat('a',12345)),(2,'b');
UPDATE t SET a=2;
DELETE FROM t;
The UPDATE statement will fail because of a duplicate key. (A foreign key constraint violation or a lock wait timeout could do as well.)
I wrongly assumed that the externally stored column b of the record (1,repeat('a',12345)) should be marked "not owned", and it will not be freed by purge. It is marked "owned" again by this code:
#0 mlog_write_ulint (ptr=0xb6a246e3 "", val=<value optimized out>, type=1 '\001', mtr=0xb1e8717c) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/mtr/mtr0log.c:270
#1 0x083dbcd1 in btr_cur_unmark_extern_fields (page_zip=<value optimized out>, rec=<value optimized out>, index=0x89f4088, offsets=0xb1e86e78, mtr=0xb1e8717c) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/btr/btr0cur.c:3730
#2 0x083e4192 in btr_cur_update_in_place (flags=<value optimized out>, cursor=0x89f67ec, update=0x89f6968, cmpl_info=0, thr=0x89f6738, mtr=0xb1e8717c) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/btr/btr0cur.c:1915
#3 0x083e46be in btr_cur_optimistic_update (flags=7, cursor=0x89f67ec, update=0x89f6968, cmpl_info=0, thr=0x89f6738, mtr=0xb1e8717c) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/btr/btr0cur.c:1996
#4 0x08474024 in row_undo_mod_clust_low (node=0x89f6798, thr=0x0, mtr=0xb6a246e3, mode=2) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0umod.c:128
#5 0x08474aa5 in row_undo_mod_clust (node=0x89f6798, thr=<value optimized out>) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0umod.c:258
#6 0x084752c3 in row_undo_mod (node=0x89f6798, thr=0x89f6738) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0umod.c:888
#7 0x0846f8c6 in row_undo (thr=0x89f6738) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0undo.c:325
#8 row_undo_step (thr=0x89f6738) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0undo.c:367
#9 0x08465d0d in que_thr_step (thr=0x89f6738) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/que/que0que.c:1245
#10 que_run_threads_low (thr=0x89f6738) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/que/que0que.c:1310
#11 que_run_threads (thr=0x89f6738) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/que/que0que.c:1347
#12 0x083c2a81 in trx_general_rollback_for_mysql (trx=0x89e3100, savept=0xb1e87854) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/trx/trx0roll.c:97
#13 0x08398877 in row_mysql_handle_errors (new_err=0xb1e8785c, trx=0x89e3100, thr=0x89f4568, savept=0xb1e87854) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0mysql.c:589
#14 0x08398c3e in row_update_for_mysql (mysql_rec=0x89f2ee0 "\376\001", prebuilt=0x89f3190) at /home/marko/innobase/dev/mysql-5.5/storage/innobase/row/row0mysql.c:1459
I seem to remember that a lock wait timeout does not always result in a transaction rollback, depending on configuration options. We should review that.
[3 Aug 2010 12:59]
Marko Mäkelä
I checked the lock wait timeout case, and btr_free_externally_stored_field() was invoked by the master thread in order to free the BLOB after the DELETE statement.
Thus, Sunny's fix is complete, and my concern is invalid. For the record, here is my test case, ran with both --innodb-rollback-on-timeout=0 and --innodb-rollback-on-timeout=1:
-- source include/have_innodb.inc
CREATE TABLE t(a INT PRIMARY KEY,b TEXT)ENGINE=InnoDB;
INSERT INTO t VALUES(1,repeat('a',12345)),(2,'b');
-- connect (con1,localhost,root,,)
-- connection con1
BEGIN;
UPDATE t SET b=NULL WHERE a=2;
-- connection default
SET SESSION innodb_lock_wait_timeout=1;
-- error ER_LOCK_WAIT_TIMEOUT
UPDATE t SET a=2;
-- connection con1
DELETE FROM t;
COMMIT;
-- disconnect con1
-- connection default
DROP TABLE t;
[23 Aug 2010 11:30]
Marko Mäkelä
Bug #55981 could be related to this.b
[25 Aug 2010 8:38]
Marko Mäkelä
Bug #56173 is another duplicate of this.
[28 Sep 2010 8:47]
Bugs System
Pushed into mysql-5.1 5.1.52 (revid:sunanda.menon@sun.com-20100928083322-wangbv97uobu7g66) (version source revid:sunanda.menon@sun.com-20100928083322-wangbv97uobu7g66) (merge vers: 5.1.52) (pib:21)
[14 Oct 2010 8:26]
Bugs System
Pushed into mysql-5.1-telco-7.0 5.1.51-ndb-7.0.20 (revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (version source revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (merge vers: 5.1.51-ndb-7.0.20) (pib:21)
[14 Oct 2010 8:41]
Bugs System
Pushed into mysql-5.1-telco-6.3 5.1.51-ndb-6.3.39 (revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (version source revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (merge vers: 5.1.51-ndb-6.3.39) (pib:21)
[14 Oct 2010 8:56]
Bugs System
Pushed into mysql-5.1-telco-6.2 5.1.51-ndb-6.2.19 (revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (version source revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (merge vers: 5.1.51-ndb-6.2.19) (pib:21)
[1 Nov 2010 11:30]
Marko Mäkelä
I believe that a more complete fix is needed in order to counter Bug #55248.
[2 Nov 2010 13:20]
Marko Mäkelä
Note: this bug was not fixed in the built-in InnoDB of MySQL 5.1. The fix is only in the InnoDB Plugin of MySQL 5.1, and in MySQL 5.5 and later. I think that Bug #55284 (a superset of this bug) can be fixed in the built-in InnoDB of MySQL 5.1. The bug exists in all MySQL/InnoDB versions, starting with 3.23.53.
[9 Nov 2010 19:46]
Bugs System
Pushed into mysql-5.5 5.5.7-rc (revid:sunanda.menon@sun.com-20101109182959-otkxq8vo2dcd13la) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (merge vers: 5.1.50) (pib:21)
[12 Nov 2010 4:26]
Roel Van de Paar
Confirmed not-reproducible in 5.5.7rc (reproducible, easily, in 5.5.6rc)
[13 Nov 2010 16:10]
Bugs System
Pushed into mysql-trunk 5.6.99-m5 (revid:alexander.nozdrin@oracle.com-20101113155825-czmva9kg4n31anmu) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (merge vers: 5.1.50) (pib:21)
[13 Nov 2010 16:35]
Bugs System
Pushed into mysql-next-mr (revid:alexander.nozdrin@oracle.com-20101113160336-atmtmfb3mzm4pz4i) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (pib:21)
[1 Dec 2010 7:07]
Marko Mäkelä
I would say that this is a subset of Bug #55284, or that the committed fix of Bug #55284 is incomplete. The full fix will be in Bug #55284. Also, note that the Bug #55543 fix was was not committed to the built-in InnoDB in MySQL 5.1; only to the InnoDB Plugin in 5.1, and to MySQL 5.5 and later.
[1 Dec 2010 7:10]
Marko Mäkelä
Sorry, I meant that the committed fix of Bug #55543 is incomplete. The fix of Bug #55284 has not been committed yet.
[27 Jan 2011 19:13]
John Russell
Added to changelog for 5.5.7 and 5.1.51: The server could crash with an assertion, possibly leading to data corruption, while updating the primary key of an InnoDB table containing BLOB or other columns requiring off-page storage. This fix applies to the InnoDB Plugin in MySQL 5.1, and to InnoDB 1.1 in MySQL 5.5.
