Bug#12809202 61854: MYSQLDUMP --SINGLE-TRANSACTION

             --FLUSH-LOG BREAKS CONSISTENCY

The transaction started by mysqldump gets committed
implicitly when flush-log is specified along with
single-transaction option, and hence can break
consistency.

This is because, COM_REFRESH is executed in order
to flush logs and starting from 5.5 this command
performs an implicit commit.

Fixed by making sure that COM_REFRESH is executed
before the transaction has started and not after it.

Note : This patch triggers following behavioral
       changes in mysqldump :

1) After this patch we no longer flush logs before
   dumping each database if --single-transaction
   option is given like it was done before (in the
   absence of --lock-all-tables and --master-data
   options).

2) Also, after this patch, we start acquiring
   FTWRL before flushing logs in cases when only
   --single-transaction and --flush-logs are given.
   It becomes safe to use mysqldump with these two
   options and without --master-data parameter for
   backups.


client/mysqldump.c:
  Bug#12809202 61854: MYSQLDUMP --SINGLE-TRANSACTION
               --FLUSH-LOG BREAKS CONSISTENCY
  
  Added logic to make sure that, if flush-log option
  is specified, mysql_refresh() is never executed after
  the transaction has started.
  
  Added verbose messages for all the executions of
  mysql_refresh() in order to track its invocation.
mysql-test/r/mysqldump.result:
  Added test case for Bug#12809202.
mysql-test/t/mysqldump.test:
  Added test case for Bug#12809202.

client/mysqldump.c

@@ -4079,6 +4079,8 @@ static int dump_all_tables_in_db(char *database)
     if (mysql_refresh(mysql, REFRESH_LOG))
       DB_error(mysql, "when doing refresh");
            /* We shall continue here, if --force was given */
+    else
+      verbose_msg("-- dump_all_tables_in_db : logs flushed successfully!\n");
   }
   while ((table= getTableName(0)))
   {
@@ -4179,6 +4181,8 @@ static my_bool dump_all_views_in_db(char *database)
     if (mysql_refresh(mysql, REFRESH_LOG))
       DB_error(mysql, "when doing refresh");
            /* We shall continue here, if --force was given */
+    else
+      verbose_msg("-- dump_all_views_in_db : logs flushed successfully!\n");
   }
   while ((table= getTableName(0)))
   {
@@ -4317,6 +4321,8 @@ static int dump_selected_tables(char *db, char **table_names, int tables)
       DB_error(mysql, "when doing refresh");
     }
      /* We shall countinue here, if --force was given */
+    else
+      verbose_msg("-- dump_selected_tables : logs flushed successfully!\n");
   }
   if (opt_xml)
     print_xml_tag(md_result_file, "", "\n", "database", "name=", db, NullS);
@@ -4600,6 +4606,7 @@ static int purge_bin_logs_to(MYSQL *mysql_con, char* log_name)
 
 static int start_transaction(MYSQL *mysql_con)
 {
+  verbose_msg("-- Starting transaction...\n");
   /*
     We use BEGIN for old servers. --single-transaction --master-data will fail
     on old servers, but that's ok as it was already silently broken (it didn't
@@ -5199,24 +5206,39 @@ int main(int argc, char **argv)
   if (opt_slave_data && do_stop_slave_sql(mysql))
     goto err;
 
-  if ((opt_lock_all_tables || opt_master_data) &&
+  if ((opt_lock_all_tables || opt_master_data ||
+       (opt_single_transaction && flush_logs)) &&
       do_flush_tables_read_lock(mysql))
     goto err;
-  if (opt_single_transaction && start_transaction(mysql))
-      goto err;
-  if (opt_delete_master_logs)
+
+  /*
+    Flush logs before starting transaction since
+    this causes implicit commit starting mysql-5.5.
+  */
+  if (opt_lock_all_tables || opt_master_data ||
+      (opt_single_transaction && flush_logs) ||
+      opt_delete_master_logs)
+  {
+    if (flush_logs || opt_delete_master_logs)
     {
-    if (mysql_refresh(mysql, REFRESH_LOG) ||
-        get_bin_log_name(mysql, bin_log_name, sizeof(bin_log_name)))
+      if (mysql_refresh(mysql, REFRESH_LOG))
         goto err;
+      verbose_msg("-- main : logs flushed successfully!\n");
+    }
+
+    /* Not anymore! That would not be sensible. */
     flush_logs= 0;
   }
-  if (opt_lock_all_tables || opt_master_data)
+
+  if (opt_delete_master_logs)
   {
-    if (flush_logs && mysql_refresh(mysql, REFRESH_LOG))
+    if (get_bin_log_name(mysql, bin_log_name, sizeof(bin_log_name)))
       goto err;
-    flush_logs= 0; /* not anymore; that would not be sensible */
   }
+
+  if (opt_single_transaction && start_transaction(mysql))
+    goto err;
+
   /* Add 'STOP SLAVE to beginning of dump */
   if (opt_slave_apply && add_stop_slave())
     goto err;

mysql-test/r/mysqldump.result

@@ -4662,3 +4662,103 @@ UNLOCK TABLES;
 /*!40111 SET SQL_NOTES=@OLD_SQL_NOTES */;
 
 DROP TABLE t1;
+#
+# Bug#12809202 61854: MYSQLDUMP --SINGLE-TRANSACTION --FLUSH-LOG BREAKS
+#                     CONSISTENCY
+#
+DROP DATABASE IF EXISTS b12809202_db;
+CREATE DATABASE b12809202_db;
+CREATE TABLE b12809202_db.t1 (c1 INT);
+CREATE TABLE b12809202_db.t2 (c1 INT);
+INSERT INTO b12809202_db.t1 VALUES (1), (2), (3);
+INSERT INTO b12809202_db.t2 VALUES (1), (2), (3);
+# Starting mysqldump with --single-transaction & --flush-log options..
+# Note : In the following dump the transaction
+#        should start only after the logs are
+#        flushed, as 'flush logs' causes implicit
+#        commit starting 5.5.
+
+#### Dump starts here ####
+-- Connecting to localhost...
+-- main : logs flushed successfully!
+-- Starting transaction...
+-- Retrieving table structure for table t1...
+-- Sending SELECT query...
+-- Retrieving rows...
+--
+-- Host: localhost    Database: b12809202_db
+-- ------------------------------------------------------
+
+/*!40101 SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT */;
+/*!40101 SET @OLD_CHARACTER_SET_RESULTS=@@CHARACTER_SET_RESULTS */;
+/*!40101 SET @OLD_COLLATION_CONNECTION=@@COLLATION_CONNECTION */;
+/*!40101 SET NAMES utf8 */;
+/*!40103 SET @OLD_TIME_ZONE=@@TIME_ZONE */;
+/*!40103 SET TIME_ZONE='+00:00' */;
+/*!40014 SET @OLD_UNIQUE_CHECKS=@@UNIQUE_CHECKS, UNIQUE_CHECKS=0 */;
+/*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */;
+/*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, SQL_MODE='NO_AUTO_VALUE_ON_ZERO' */;
+/*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0 */;
+
+--
+-- Table structure for table `t1`
+--
+
+DROP TABLE IF EXISTS `t1`;
+/*!40101 SET @saved_cs_client     = @@character_set_client */;
+/*!40101 SET character_set_client = utf8 */;
+CREATE TABLE `t1` (
+  `c1` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1;
+/*!40101 SET character_set_client = @saved_cs_client */;
+
+--
+-- Dumping data for table `t1`
+--
+
+LOCK TABLES `t1` WRITE;
+/*!40000 ALTER TABLE `t1` DISABLE KEYS */;
+INSERT INTO `t1` VALUES (1),(2),(3);
+-- Retrieving table structure for table t2...
+-- Sending SELECT query...
+-- Retrieving rows...
+/*!40000 ALTER TABLE `t1` ENABLE KEYS */;
+UNLOCK TABLES;
+
+--
+-- Table structure for table `t2`
+--
+
+DROP TABLE IF EXISTS `t2`;
+/*!40101 SET @saved_cs_client     = @@character_set_client */;
+/*!40101 SET character_set_client = utf8 */;
+CREATE TABLE `t2` (
+  `c1` int(11) DEFAULT NULL
+) ENGINE=MyISAM DEFAULT CHARSET=latin1;
+/*!40101 SET character_set_client = @saved_cs_client */;
+
+--
+-- Dumping data for table `t2`
+--
+
+LOCK TABLES `t2` WRITE;
+/*!40000 ALTER TABLE `t2` DISABLE KEYS */;
+INSERT INTO `t2` VALUES (1),(2),(3);
+/*!40000 ALTER TABLE `t2` ENABLE KEYS */;
+UNLOCK TABLES;
+-- Disconnecting from localhost...
+/*!40103 SET TIME_ZONE=@OLD_TIME_ZONE */;
+
+/*!40101 SET SQL_MODE=@OLD_SQL_MODE */;
+/*!40014 SET FOREIGN_KEY_CHECKS=@OLD_FOREIGN_KEY_CHECKS */;
+/*!40014 SET UNIQUE_CHECKS=@OLD_UNIQUE_CHECKS */;
+/*!40101 SET CHARACTER_SET_CLIENT=@OLD_CHARACTER_SET_CLIENT */;
+/*!40101 SET CHARACTER_SET_RESULTS=@OLD_CHARACTER_SET_RESULTS */;
+/*!40101 SET COLLATION_CONNECTION=@OLD_COLLATION_CONNECTION */;
+/*!40111 SET SQL_NOTES=@OLD_SQL_NOTES */;
+
+-- Dump completed
+#### Dump ends here ####
+DROP TABLE b12809202_db.t1;
+DROP TABLE b12809202_db.t2;
+DROP DATABASE b12809202_db;

mysql-test/t/mysqldump.test

@@ -2215,5 +2215,37 @@ CREATE TABLE t1 (a INT);
 --exec $MYSQL_DUMP --compatible=no_t,no_f --skip-comments test
 DROP TABLE t1;
 
+--echo #
+--echo # Bug#12809202 61854: MYSQLDUMP --SINGLE-TRANSACTION --FLUSH-LOG BREAKS
+--echo #                     CONSISTENCY
+--echo #
+
+--disable_warnings
+DROP DATABASE IF EXISTS b12809202_db;
+--enable_warnings
+
+CREATE DATABASE b12809202_db;
+CREATE TABLE b12809202_db.t1 (c1 INT);
+CREATE TABLE b12809202_db.t2 (c1 INT);
+
+INSERT INTO b12809202_db.t1 VALUES (1), (2), (3);
+INSERT INTO b12809202_db.t2 VALUES (1), (2), (3);
+
+--echo # Starting mysqldump with --single-transaction & --flush-log options..
+--echo # Note : In the following dump the transaction
+--echo #        should start only after the logs are
+--echo #        flushed, as 'flush logs' causes implicit
+--echo #        commit starting 5.5.
+--echo
+--echo #### Dump starts here ####
+--replace_regex /-- Server version.*// /-- MySQL dump .*// /-- Dump completed on .*/-- Dump completed/
+--exec $MYSQL_DUMP --verbose --single-transaction --flush-log b12809202_db 2>&1
+--echo
+--echo #### Dump ends here ####
+
+DROP TABLE b12809202_db.t1;
+DROP TABLE b12809202_db.t2;
+DROP DATABASE b12809202_db;
+
 # Wait till we reached the initial number of concurrent sessions
 --source include/wait_until_count_sessions.inc