Bug #41716 Backup Error when sending data (for table #1) to Default/Snapshot restore driver
Submitted: 23 Dec 2008 15:42 Modified: 3 Mar 2010 15:31
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Backup Severity:S1 (Critical)
Version:6.0-backup OS:Any
Assigned to: Ingo Strüwing CPU Architecture:Any
Tags: mdl

[23 Dec 2008 15:42] Philip Stoev
Description:
When attempting a RESTORE on a Falcon BACKUP, the following error occurs:

ERROR 1670 (HY000): Error when sending data (for table #1) to Snapshot restore driver

error log is not helpful:

081223 18:40:28 [Note] Restore: Starting restore process
081223 18:40:28 [Note] Restore: Restoring 1 database(s) `test`
081223 18:40:28 [Warning] Restore: The grant 'ALTER ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'CREATE ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'CREATE ROUTINE ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'CREATE TEMPORARY TABLES ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'CREATE VIEW ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'DELETE ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'DROP ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'EVENT ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'INDEX ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'INSERT ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'LOCK TABLES ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'REFERENCES ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'SELECT ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'SHOW VIEW ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'TRIGGER ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:28 [Warning] Restore: The grant 'UPDATE ON test.*' for the user ''@'%' was skipped because the user does not exist.
081223 18:40:47 [ERROR] Restore: Error when sending data (for table #1) to Snapshot restore driver
081223 18:40:49 [Note] Restore: Restore completed

How to repeat:
Restore the attached backup.
[23 Dec 2008 15:44] Philip Stoev
Backup for bug 41716

Attachment: bug41716-backup.zip (application/x-zip-compressed, text), 28.14 KiB.

[23 Dec 2008 15:49] Philip Stoev
Test case:

create table t1 (f1 integer) engine=falcon;
insert into t1 values (1);
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
insert into t1 select * from t1;
backup database test to '/tmp/b1';
restore from '/tmp/b1' overwrite;

Table contains 1.048.576 rows before backup. After restore, zero rows.
[26 Jan 2009 13:48] Susanne Ebrecht
Bug #42159 is set as duplicate of this bug here.
[1 Feb 2009 13:05] Philip Stoev
This error was also observed with Maria. Unfortunately, the error is not specific enough to know if it is the same issue.
[3 Feb 2009 16:56] Guilhem Bichot
Testcase:
1) patch like this:
=== modified file 'sql/backup/kernel.cc'
--- sql/backup/kernel.cc        2009-01-26 11:20:22 +0000
+++ sql/backup/kernel.cc        2009-02-03 16:41:46 +0000
@@ -1262,6 +1262,8 @@
   close_thread_tables(m_thd);                   // Never errors
   m_thd->main_da.reset_diagnostics_area();      // Never errors

+  fprintf(stderr, "insert into me please\n");
+  sleep(10);
   err= lock_tables_for_restore();               // logs errors
   if (err)
     DBUG_RETURN(fatal_error(err));

(i.e. a sleep when RESTORE is between create and lock).

2) run this test:
--disable_warnings
DROP DATABASE IF EXISTS mysqltest;
--error 0,1
--remove_file $MYSQLTEST_VARDIR/master-data/test.ba
--enable_warnings

CREATE DATABASE mysqltest;
USE mysqltest;
CREATE TABLE t1 (a int, b varchar(100), unique(a)) engine=memory;
insert into t1 values(1,"abc");

--replace_column 1 #
BACKUP DATABASE mysqltest TO 'test.ba';
DROP DATABASE mysqltest;
--replace_column 1 #
RESTORE FROM 'test.ba';
select * from t1;
flush tables;
select * from t1;

--echo
--echo connection default: cleanup
connection default;
drop database mysqltest;
--remove_file $MYSQLTEST_VARDIR/master-data/test.ba

With mtr. While it's in the sleep, open another connection and do:
insert into t1 values(1,"def");
Then RESTORE, when it wakes up, will print:
mysqltest: At line 16: query 'RESTORE FROM 'test.ba'' failed: 1670: Error when sending data (for table #1) to Default restore driver

I verified this with 6.0-maria but this is not involving Maria tables so I suspect it could exist in 6.0-main too.
[6 Feb 2009 9:30] Guilhem Bichot
I am attaching a patch (with debug sync points) and test which reproduces the problem with default and snapshot drivers.
The problem has been described already: after RESTORE has recreated the table empty and before it locks it (to fill it), a client manages to lock the table, and do a change to it (in the test, an INSERT). Later RESTORE writes rows to the table but one row conflicts (duplicate key) with what the INSERT client has inserted, RESTORE throws this error.
Example of error shown by the test:
mysqltest: At line 35: query 'reap' failed: 1670: Error when sending data (for table #1) to Snapshot restore driver
The test uses Falcon, change to MEMORY to provoke the bug with the default lock-based driver.
[6 Feb 2009 9:31] Guilhem Bichot
repeatable test

Attachment: bug41716.test (application/octet-stream, text), 1.04 KiB.

[6 Feb 2009 9:31] Guilhem Bichot
and here is the patch with sync points used by the test:
=== modified file 'sql/backup/kernel.cc'
--- sql/backup/kernel.cc        2009-02-03 07:48:09 +0000
+++ sql/backup/kernel.cc        2009-02-06 09:13:32 +0000
@@ -1324,10 +1324,14 @@
   close_thread_tables(m_thd);                   // Never errors
   m_thd->stmt_da->reset_diagnostics_area();     // Never errors

+  DEBUG_SYNC(m_thd, "before_restore_locks_tables");
+
   err= lock_tables_for_restore();               // logs errors
   if (err)
     DBUG_RETURN(fatal_error(err));

+  DEBUG_SYNC(m_thd, "after_restore_locks_tables");
+
   /*
    Here restore drivers are created to restore table data. Data is being
    (potentially) changed so we set m_data_changed flag.
[11 Feb 2009 10:28] Sveta Smirnova
Can be related to bug #41722
[14 Feb 2009 17:12] Ingo Strüwing
I could verify Guilhems analyze. So this bug is waiting for the same as Bug#40944 (Backup: crash after myisampack):

Waiting for the runtime team to provide an open_and_lock_tables(), which accepts name locks (exclusive mdl locks) on the tables.
[23 Feb 2009 12:12] Ingo Strüwing
Depends on Bug#42895 (Please implement a table open interface for name-locked tables)
[8 Jun 2009 15:58] Ingo Strüwing
To be more specific: We need a lock, that prevents other statements to access
the tables in restore even if they are not (yet) opened by RESTORE.
This is the intention for Bug#42895/WL#4844.
[17 Nov 2009 16:26] Ingo Strüwing
The patch for Bug#42895/Wl#4844 (Implement a locking scheme for RESTORE) solves this bug too. Queued to mysql-6.0-backup.
[20 Feb 2010 9:18] Bugs System
Pushed into 6.0.14-alpha (revid:ingo.struewing@sun.com-20100218152520-s4v1ld76bif06eqn) (version source revid:ingo.struewing@sun.com-20100119103538-wtp5alpz4p2jayl5) (merge vers: 6.0.14-alpha) (pib:16)
[3 Mar 2010 8:19] Ingo Strüwing
Due to improper locking, another connection could insert rows into a table being restored, thus causing duplicate key errors. The resulting error message was meaningless.
[3 Mar 2010 15:31] Paul DuBois
Noted in 6.0.14 changelog.