Bug #29081 mysqld crash following "LOAD DATA INFILE..." with Falcon
Submitted: 13 Jun 2007 16:47 Modified: 3 Dec 2007 14:23
Reporter: Anthony Willard (Basic Quality Contributor) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0.0-alpha-community-nt-debug OS:Windows (XP SP2/Vista X64)
Assigned to: Ann Harrison CPU Architecture:Any

[13 Jun 2007 16:47] Anthony Willard
Description:
Mysql daemon process crashes when attempting to load a large amount of data for testing.

With a smaller set of data, the process loads the data and mysql returns, and while apparently completing the transaction it dies.  

With larger data, the amount of data piles up causing the crash to happen some time later but mysql never completes until the server process dies.

How to repeat:
I will attach a ZIP file containing a test SQL script and a data input file to use with the script.  I was not able to distill down the data to a more simple test case, but this data more closely matches what I found in my specific test scenario.

I've included the various dump files from Windows to aid analysis.

* modify the bug_script.sql to locate the input data file

run a command, similar to "mysql --host=127.0.0.1 --user=someuser --password=somepass < bug_script.sql"

Suggested fix:
Review the transaction commit logic for the Falcon engine and LOAD DATA INFILE with large data.
[13 Jun 2007 16:53] Anthony Willard
I've uploaded a file "bug-data-29081.zip" to the FTP server.
[13 Jun 2007 16:59] Anthony Willard
Between each test, I removed all tables in the test database, and removed the test Falcon (fl1, fl2, fts) files, and started the server.

I have the basic settings from the install, with no tuning.  Let me know if you need my settings.
[14 Jun 2007 11:10] Hakan Küçükyılmaz
Anthony,

this is fixed in latest version of Falcon:

hakan@lu0011:~/downloads$ mysql -uroot test < bug_script.sql
hakan@lu0011:~/downloads$ mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 6.0.1-alpha-debug Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

[13:05] root@test>select count(*) from t1;
+----------+
| count(*) |
+----------+
|  1200000 |
+----------+
1 row in set (1 min 38.86 sec)

Best regards,

Hakan
[14 Jun 2007 12:28] Anthony Willard
Hakan, did you test this on the Windows configuration or *nix?  

On Windows, the mysql tool completes, then a few minutes later the error shows up as the mysqld process crashes.

If it is truly corrected in 6.0.1+, when will that fix be available to test?
[14 Jun 2007 19:26] MySQL Verification Team
Thank you for the bug report. I was able to repeat with a Windows X64
Falcon server built from the changeset printed at the bottom.

    ->   KEY `ClaimRangeData` (`GroupID`,`PaidDate`,`TreatmentStartDate`),
    ->   KEY `ByMember` (`EmployeeSSN`,`DependentNumber`,`PaidDate`,`TreatmentStartDate`),
    ->   KEY `ByProvider` (`BillingProviderTIN`,`PaidDate`),
    ->   KEY `ByFamily` (`EmployeeSSN`,`PaidDate`,`TreatmentStartDate`)
    ->
    -> ) ENGINE=FALCON DEFAULT CHARSET=latin1 COMMENT='Test table';
Query OK, 0 rows affected (0.49 sec)

mysql> load data infile "c:/script/bug_data.dat" into table t1 fields terminated by "\t" lines terminated by "\n";
Query OK, 1200000 rows affected (2 min 9.76 sec)
Records: 1200000  Deleted: 0  Skipped: 0  Warnings: 0

c:\build\x64\6.0>bin\mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 6.0.1-alpha-nt Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> select count(*) from t1;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql>

C:\build\x64\6.0>bin\mysqld-nt --standalone --console
070614 16:07:45  InnoDB: Started; log sequence number 0 46409
070614 16:07:46 [Note] Event Scheduler: Loaded 0 events
070614 16:07:46 [Note] bin\mysqld-nt: ready for connections.
Version: '6.0.1-alpha-nt'  socket: ''  port: 3306  Source distribution
Recovering database C:\build\x64\6.0\data\falcon_master.fts ...
first recovery block is 1
last recovery block is 748
recovery read block is 78
Bugcheck: assertion failed at line 461 in file .\Section.cpp

Memory

Module  Line    In Use  Space in Use    Deleted Space deleted
*unknown*       0       22      15166464        146111  10030956
Total           22      15166464        146111  10030956
Number small hunks:     5
Number big hunks:       3
Unique sizes: 1
Free segments:  1
Free space:     1615048
Records

Module  Line    In Use  Space in Use    Deleted Space deleted
Total           0       0       0       0
Number small hunks:     0
Number big hunks:       0
Unique sizes: 0
Free segments:  0
Free space:     0

c:\build\x64\6.0>bin\mysql -uroot
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 6.0.1-alpha-nt Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> show variables like "%version%"
    -> ;
+-------------------------+---------------------+
| Variable_name           | Value               |
+-------------------------+---------------------+
| protocol_version        | 10                  |
| version                 | 6.0.1-alpha-nt      |
| version_comment         | Source distribution |
| version_compile_machine | unknown             |
| version_compile_os      | Win64               |
+-------------------------+---------------------+
5 rows in set (0.00 sec)

mysql>

[miguel@light mysql-5.1-falcon]$ bk changes | head
ChangeSet@1.2568, 2007-06-13 14:20:08-04:00, jas@rowvwade. +1 -0
  Recover from lost tip page.

ChangeSet@1.2567, 2007-06-13 13:49:42-04:00, jas@rowvwade. +4 -0
  Finish implementation of drop tablepace.

ChangeSet@1.2566, 2007-06-13 13:05:15-04:00, jas@rowvwade. +9 -0
  Extend database validation to table spaces.

ChangeSet@1.2565, 2007-06-13 11:49:23-04:00, jas@rowvwade. +5 -0
[25 Jun 2007 20:18] Ann Harrison
The proximate cause of the crash was an unhandled exception in
rollback code.  The cause of the exception and the rollback was
running out of cache buffers, an error that can never happen 
unless there are more threads than buffers.  Which was not the
case.  Correcting the order of precedence of two page types 
made it possible to release unloved pages from the cache.
[28 Nov 2007 15:39] MySQL Verification Team
Hakan,

I can't repeat anymore with latest source tree:

    ->   KEY `ClaimRangeData2` (`PaidDate`,`GroupID`,`TreatmentStartDate`),
    ->   KEY `ClaimRangeData` (`GroupID`,`PaidDate`,`TreatmentStartDate`),
    ->   KEY `ByMember` (`EmployeeSSN`,`DependentNumber`,`PaidDate`,`TreatmentStartDate`),
    ->   KEY `ByProvider` (`BillingProviderTIN`,`PaidDate`),
    ->   KEY `ByFamily` (`EmployeeSSN`,`PaidDate`,`TreatmentStartDate`)
    ->
    -> ) ENGINE=FALCON DEFAULT CHARSET=latin1 COMMENT='Test table';
Query OK, 0 rows affected (0.69 sec)

mysql> load data infile "c:/t/bug_data.dat" into table t1 fields terminated by "\t" lines terminated by "\n";
Query OK, 1200000 rows affected (2 min 24.30 sec)
Records: 1200000  Deleted: 0  Skipped: 0  Warnings: 0

mysql> exit
Bye

c:\dev>6.0\bin\mysql -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 6.0.4-alpha-nt Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> select count(*) from t1;
+----------+
| count(*) |
+----------+
|  1200000 |
+----------+
1 row in set (32.43 sec)

mysql>
[3 Dec 2007 14:23] MC Brown
A note has been added to the 6.0.4 changelog: 

When loading large data sets using LOAD DATA INFILE into a Falcon table, the server could crash.