MySQL Bugs: #26850: Falcon: crash with random inserts of long varchar columns

Bug #26850	Falcon: crash with random inserts of long varchar columns
Submitted:	5 Mar 2007 21:56	Modified:	20 Apr 2007 14:54
Reporter:	Peter Gulutzan	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S3 (Non-critical)
Version:	5.2.4-falcon-alpha-debug	OS:	Linux (SUSE 10.0 / 64-bit)
Assigned to:		CPU Architecture:	Any

Description:
I have a Falcon table with three columns, one index.
Two columns are long VARCHAR columns.
I create a procedure which inserts into the table,
with random character values and character lengths.
The procedure crashes after a few iterations.
The database becomes corrupt.

The description reminds me of
Bug#23818 Falcon: crash with random updates of long varchar columns
which is now closed.

ChangeSet@1.2463, 2007-03-04 15:23:13+01:00

How to repeat:
delimiter //
create procedure pj ()
begin
  declare v int default 0;
  declare vc1 varchar(100);
  declare vc2 varchar(1000);
  create table tj (s1 int, s2 varchar(100), s3 varchar(10000)) engine=falcon;
  create index i on tj (s2(100),s3(1000));
  while v < 10000 do
    set vc1 = repeat('a',rand()*99);
    set vc2 = repeat('a',999);
    select v, length(vc1);
    insert into tj values (v,vc1,vc2);
    set v = v + 1;
    end while;
  end//
call pj()//

After a few (fewer than 1000) repetitions of the loop, you should see
something like:

...

+------+-------------+
| v    | length(vc1) |
+------+-------------+
|   75 |          97 |
+------+-------------+
1 row in set (0.54 sec)

ERROR 2013 (HY000): Lost connection to MySQL server during query

You should also see a crash if you restart the server and try to
access table tj again.

Reproduced as described.

+------+-------------+
| v    | length(vc1) |
+------+-------------+
| 3518 |          51 |
+------+-------------+
1 row in set (56.41 sec)

+------+-------------+
| v    | length(vc1) |
+------+-------------+
| 3519 |          98 |
+------+-------------+
1 row in set (56.43 sec)

Backtrace is:

#0  0xffffe410 in __kernel_vsyscall ()
#1  0x40182541 in raise () from /lib/tls/libc.so.6
#2  0x08458292 in Error::debugBreak () at Error.cpp:93
#3  0x084582ef in Error::error (string=0x8765198 "assertion failed at line %d in file %s\n") at Error.cpp:70
#4  0x0845837f in Error::assertionFailed (fileName=0x87666dc "IndexNode.h", line=134) at Error.cpp:77
#5  0x08469909 in IndexNode::expandKey (this=0x42b5f710, indexKey=0x42b5f7b4) at IndexNode.h:134
#6  0x08468816 in IndexPage::findInsertionPoint (level=1, indexKey=0x42b607f4, recordNumber=1484,
    expandedKey=0x42b5f7b4, nodes=0x41b9d034, bucketEnd=0x41b9da1b) at IndexPage.cpp:1135
#7  0x08468892 in IndexPage::findInsertionPoint (this=0x41b9d000, indexKey=0x42b607f4, recordNumber=1484,
    expandedKey=0x42b5f7b4) at IndexPage.cpp:973
#8  0x08468919 in IndexPage::addNode (this=0x41b9d000, dbb=0x404fab3c, indexKey=0x42b607f4, recordNumber=1484)
    at IndexPage.cpp:58
#9  0x0846a9e9 in IndexRootPage::splitIndexPage (dbb=0x404fab3c, indexId=29, bdb=0x417848d0, transId=0,
    addResult=SplitMiddle, indexKey=0x42b62874, recordNumber=3519) at IndexRootPage.cpp:552
#10 0x0846ade4 in IndexRootPage::addIndexEntry (dbb=0x404fab3c, indexId=29, key=0x42b62874, recordNumber=3519,
    transId=0) at IndexRootPage.cpp:185
#11 0x0846be31 in IndexRootPage::indexMerge (dbb=0x404fab3c, indexId=29, logRecord=0x42b632a4, transId=0)
    at IndexRootPage.cpp:945
#12 0x084bdbd6 in SRLUpdateIndex::execute (this=0x42b632a4) at SRLUpdateIndex.cpp:155
#13 0x084bdc53 in SRLUpdateIndex::commit (this=0x42b632a4) at SRLUpdateIndex.cpp:135
#14 0x084a7413 in SerialLogTransaction::commit (this=0x405cd708) at SerialLogTransaction.cpp:70
#15 0x084a7704 in SerialLogTransaction::doAction (this=0x405cd708) at SerialLogTransaction.cpp:127
#16 0x084a196a in SerialLog::gopherThread (this=0x41795614) at SerialLog.cpp:156
#17 0x084a1a8a in SerialLog::gopherThread (arg=0x41795614) at SerialLog.cpp:121
#18 0x08425481 in Thread::thread (this=0x40501b28) at Thread.cpp:162
#19 0x08425941 in Thread::thread (parameter=0x40501b28) at Thread.cpp:139
#20 0x40284297 in start_thread () from /lib/tls/libpthread.so.0
#21 0x4021937e in clone () from /lib/tls/libc.so.6
#22 0x42b63bb0 in ?? ()

Best regards,

Hakan

Added seed for rand() to get better reproducability. The following procedure hits assertion at v = 822:

set @a = 8080;
delimiter //
create procedure pj ()
begin
  declare v int default 0;
  declare vc1 varchar(100);
  declare vc2 varchar(1000);
  create table tj (s1 int, s2 varchar(100), s3 varchar(10000)) engine=falcon;
  create index i on tj (s2(100),s3(1000));
  while v < 10000 do
    set vc1 = repeat('a',rand(@a)*99);
    set vc2 = repeat('a',999);
    select v, length(vc1);
    insert into tj values (v,vc1,vc2);
    set v = v + 1;
    set @a = @a - 1;
    end while;
  end//
call pj()//

Best regards, Hakan

I had to modify the test case as the index (s2(100),s3(1000) exceeded the maximum allowed key size for Falcon.

With this modified procedure I cannot reproduce this bug anymore. 

set @a = 8080;
delimiter //
create procedure pj ()
begin
  declare v int default 0;
  declare vc1 varchar(100);
  declare vc2 varchar(1000);
  create table tj (s1 int, s2 varchar(100), s3 varchar(10000)) engine=falcon;
  create index i on tj (s2(100),s3(800));
  while v < 10000 do
    set vc1 = repeat('a',rand(@a)*99);
    set vc2 = repeat('a',799);
    select v, length(vc1);
    insert into tj values (v,vc1,vc2);
    set v = v + 1;
    set @a = @a - 1;
    end while;
  end//
call pj()//

I confirm that I can no longer see a crash with the latest build.

Activated the error message (not pushed yet).

Now we get:

[22:40] root@(none)>use test;
Database changed

[22:40] root@test>create table tj (s1 int, s2 varchar(100), s3 varchar(10000));
Query OK, 0 rows affected (0.28 sec)

[22:40] root@test>create index i on tj (s2(100),s3(1000));
ERROR 1005 (HY000): Can't create table 'test.#sql-373b_2' (errno: 140)

Please note that the 1100 bytes rule does not apply for compound indexes. The error message is as the best we could get.

After Alpha we plan to have a better solution for this use case.

Best regards,

Hakan

A note has been added to the 5.2.4 changelog.

This bug report entry has been moved to the 6.0.0 Falcon changelog.