MySQL Bugs: #41722: Restore crashes with backup of Falcon tables

Bug #41722	Restore crashes with backup of Falcon tables
Submitted:	23 Dec 2008 22:02	Modified:	26 Apr 2009 0:07
Reporter:	Sveta Smirnova	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Backup	Severity:	S3 (Non-critical)
Version:	6.0, 6.0-backup	OS:	Linux
Assigned to:	Ingo Strüwing	CPU Architecture:	Any

Description:
If backup, then restore database of Falcon tables server crashes with:

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 = 60670 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x1b4a4188
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 = 0x4be940f0 thread_stack 0x40000
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(my_print_stacktrace+0x32) [0xd8032a]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(handle_segfault+0x305) [0x71173b]
/lib64/libpthread.so.0 [0x3429e0dd40]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(default_backup::Restore::send_data(backup::Buffer&)+0x664) [0xe2887e]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(backup::restore_table_data(THD*, Restore_info&, backup::Input_stream&)+0x66e) [0xe24b5c]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(Backup_restore_ctx::do_restore(bool)+0x3b0) [0xe1f0f2]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(execute_backup_command(THD*, LEX*, String*, bool)+0x4c5) [0xe205b3]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(mysql_execute_command(THD*)+0xff0) [0x723b16]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x271) [0x72b1a9]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0xa9e) [0x72c368]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(do_command(THD*)+0x227) [0x72d8b1]
/users/ssmirnova/src/mysql-6.0-backup/sql/mysqld(handle_one_connection+0x137) [0x71aa99]
/lib64/libpthread.so.0 [0x3429e061b5]
/lib64/libc.so.6(clone+0x6d) [0x34292cd39d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x1b50b540 = restore from 'bug41641.bkp'
thd->thread_id=1
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file

How to repeat:
create database db1;
create table t1(f1 text) engine=falcon;
insert into t1 values('fdafdsfdsfdsfdsfdsfd');
insert into t1 select * from t1;
// repeat until 
mysql> insert into t1 select * from t1;
Query OK, 65536 rows affected (4.99 sec)
Records: 65536  Duplicates: 0  Warnings: 0
Create another 19 tables with same content (insert into tN select * from t1)

backup database db1 to 'bug41641.bkp';

drop database db1;

mysql> restore from 'bug41641.bkp';
ERROR 2013 (HY000): Lost connection to MySQL server during query

Suggested fix:
Don't crash

Server is accessible during restore.

Can be related to bug #41716

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/68515

2777 Ingo Struewing	2009-03-06
      Bug#41722 - Restore crashes with backup of Falcon tables
      
      Partial fix. It defeats the server crash in the reported test case.
      
      The main problem is that Falcon sporadically reports
      "out of record memory". See the bug report for further information.
      
      The cause for the crash was incomplete implementation of error
      handling during restore of table data. Restore::send_data() did not
      take into account that a reported error will not immediately stop
      the restore progress, but instead retry to call send_data() for a
      couple of times.
      
      Fixed by setting up status variables so that re-entering send_data()
      after an error does not take a wrong path.
     @ mysql-test/suite/backup/r/backup_default_debug.result
        Bug#41722 - Restore crashes with backup of Falcon tables
        New test result.
     @ mysql-test/suite/backup/t/backup_default_debug.test
        Bug#41722 - Restore crashes with backup of Falcon tables
        New test case.
     @ sql/backup/be_default.cc
        Bug#41722 - Restore crashes with backup of Falcon tables
        Added error injection to fake a deterministic write error.
        Report engine write errors as warnings to the error log.
        Reset 'mode' and 'cur_blob' so that re-entering send_data()
        does not take a wrong code path.

The above patch is just a partial fix for the problem.
It defeats the crash in the RESTORE code.
But the real problem is that Falcon returns "out of record memory"
errors to the RESTORE code sporadically.
Thus RESTORE fails sporadically with "Error when sending data
(for table #1) to Snapshot restore driver".

See below for a test case that catches the problem more often
than not. But it still succeeds somtimes.

By changing the server variable or command line option
"falcon_record_memory_max", it is possible to provoke the
problem with higher probability and earlier in the test case.
To my big surprise, it didn't matter if I doubled the default
value of 250m or if I halved it.

I tried to guess that it might be possible that Falcon has kind
of a garbage collector. So I inserted sleeps of 9 seconds between
each of five attempts to call ha_write_row(), after the first
error appeared. It didn't change anything.

So I think, this bug should be reassigned to the Falcon team,
after the partial patch is accepted and pushed.

Here is my test case (it runs quite some time, say 1h):
======================================================================

SET GLOBAL falcon_record_memory_max= 262144000;
SELECT @@falcon_record_memory_max;

CREATE DATABASE mysql_db1;
CREATE TABLE mysql_db1.t01 (f1 TEXT) ENGINE=Falcon;
INSERT INTO mysql_db1.t01 VALUES('fdafdsfdsfdsfdsfdsfd');
#
--let $count= 17
while ($count)
{
  INSERT INTO mysql_db1.t01 SELECT * FROM mysql_db1.t01;
  --dec $count
}
SELECT COUNT(*) FROM mysql_db1.t01;
#
--let $count= 19
while ($count)
{
  eval CREATE TABLE mysql_db1.t$count ENGINE=Falcon SELECT * FROM mysql_db1.t01;
  --dec $count
}
#
--replace_column 1 #
BACKUP DATABASE mysql_db1 TO 'mysqltest.bak';
#
DROP DATABASE mysql_db1;
#
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
#
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
DROP DATABASE mysql_db1;
--replace_column 1 #
RESTORE FROM 'mysqltest.bak';
#
query_vertical SHOW CREATE TABLE mysql_db1.t01;
query_vertical SHOW CREATE TABLE mysql_db1.t10;
#
DROP DATABASE mysql_db1;

Proposed alternative solution and asked Ingo for opinion.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/70353

2803 Ingo Struewing	2009-03-25
      Bug#41722 - Restore crashes with backup of Falcon tables
      
      During RESTORE of a not so small Falcon table, the server crashed.
      
      The cause for the crash was an attempt to retry to send table data
      to the restore driver after an error from the restore driver.
      Restore::send_data() does not expect to be called again with
      table data after returning an error.
      
      Fixed by aborting RESTORE, if a driver returns an error.
     @ mysql-test/suite/backup/r/backup_default_debug.result
        Bug#41722 - Restore crashes with backup of Falcon tables
        New test result.
     @ mysql-test/suite/backup/t/backup_default_debug.test
        Bug#41722 - Restore crashes with backup of Falcon tables
        New test case.
     @ sql/backup/backup_engine.h
        Bug#41722 - Restore crashes with backup of Falcon tables
        Updated comments.
     @ sql/backup/be_default.cc
        Bug#41722 - Restore crashes with backup of Falcon tables
        Added error injection to fake a storage engine write error.
     @ sql/backup/data_backup.cc
        Bug#41722 - Restore crashes with backup of Falcon tables
        Dropped repetition on errors during restore of table data.

Good to push.

Approved.

Queued to mysql-6.0-backup.

Pushed into 6.0.11-alpha (revid:alik@sun.com-20090423070920-e5lq3vrrqi016z2c) (version source revid:alik@sun.com-20090423070920-e5lq3vrrqi016z2c) (merge vers: 6.0.11-alpha) (pib:6)

Noted in 6.0.11 changelog.

RESTORE crashed for Falcon tables.