Re: bzr commit into mysql-6.0-backup branch (Rafal.Somla:2734) Bug#40262

[Øystein Grøvlen]

STATUS
======

Approved when a long line has been fixed.

REQUESTS
========

1. Long line: [3]

SUGGESTIONS
===========

1. Please, consider whether sleep is necessary [1]

2. Use a single query to check all vp info [2]


Rafal Somla wrote:
> #At file:///ext/mysql/bzr/backup/bug40262/
> 
>  2734 Rafal Somla	2008-11-17
>       Bug #40262  - Binary log information incorrect in backup of no data with binlog
> 
>                     turned on
>       
>       This is the second and last patch which fixes the main problem of reporting VP
> 
>       info also in the case there are no tables to be backed-up. 
>       
>       It also fixes an issue with incorrect parsing of backup image upon restore, if
> 
>       there are no table data stored in it.
> modified:
>   mysql-test/suite/backup/r/backup.result
>   mysql-test/suite/backup/t/backup.test
>   sql/backup/data_backup.cc
>   sql/backup/image_info.cc
>   sql/backup/image_info.h
>   sql/share/errmsg.txt
> 
> per-file messages:
>   mysql-test/suite/backup/t/backup.test
>     Added a test case checking that VP info was correctly read from the image if 
>     there are no tables stored in it.
>   sql/backup/data_backup.cc
>     - Save and report VP info also if there are no tables to backup.
>     - Move the code fro storing and reporting VP info into helper functions 
>       save/report_vp_info()
>     - Fix error in restore_table_data(): if there are no tables to restore, we 
>       still need to read the 0x00 marker signaling end of table data chunks.
>   sql/backup/image_info.cc
>     Add member and method for storing master's binlog position at VP time.
>   sql/backup/image_info.h
>     Add member and method for storing master's binlog position at VP time.
> === modified file 'mysql-test/suite/backup/r/backup.result'
> --- a/mysql-test/suite/backup/r/backup.result	2008-10-07 17:15:44 +0000
> +++ b/mysql-test/suite/backup/r/backup.result	2008-11-17 14:43:10 +0000
> @@ -148,6 +148,35 @@ DROP DATABASE db1;
>  DROP DATABASE db2;
>  DROP DATABASE db3;
>  SET DEBUG_SYNC= 'RESET';
> +CREATE DATABASE db1;
> +BACKUP DATABASE db1 TO 'db1.bkp';
> +backup_id
> +#
> +SELECT MAX(backup_id) FROM mysql.backup_history INTO @bid;
> +SELECT validity_point_time FROM mysql.backup_history
> +WHERE backup_id = @bid INTO @vp_time;
> +SELECT binlog_file FROM mysql.backup_history
> +WHERE backup_id = @bid INTO @vp_file;
> +SELECT binlog_pos FROM mysql.backup_history
> +WHERE backup_id = @bid INTO @vp_pos;
> +DROP DATABASE db1;
> +RESTORE FROM 'db1.bkp';
> +backup_id
> +#
> +SELECT MAX(backup_id) FROM mysql.backup_history INTO @bid;
> +SELECT validity_point_time = @vp_time FROM mysql.backup_history
> +WHERE backup_id = @bid;
> +validity_point_time = @vp_time
> +1
> +SELECT binlog_file = @vp_file FROM mysql.backup_history
> +WHERE backup_id = @bid;
> +binlog_file = @vp_file
> +1
> +SELECT binlog_pos = @vp_pos FROM mysql.backup_history
> +WHERE backup_id = @bid;
> +binlog_pos = @vp_pos
> +1
> +DROP DATABASE db1;
>  DROP DATABASE IF EXISTS bup_default;
>  CREATE DATABASE bup_default;
>  CREATE TABLE bup_default.wide (
> 
> === modified file 'mysql-test/suite/backup/t/backup.test'
> --- a/mysql-test/suite/backup/t/backup.test	2008-10-07 17:15:44 +0000
> +++ b/mysql-test/suite/backup/t/backup.test	2008-11-17 14:43:10 +0000
> @@ -193,6 +193,52 @@ DROP DATABASE db3;
>  SET DEBUG_SYNC= 'RESET';
>  
>  #
> +# Check that PTR data (such as VP time and binlog positon) is correctly stored and
> read
> +# when there are no tables to backup (BUG#40262). 
> +#
> +
> +--error 0,1
> +--remove_file $MYSQLTEST_VARDIR/master-data/db1.bkp
> +CREATE DATABASE db1;
> +
> +--replace_column 1 #
> +BACKUP DATABASE db1 TO 'db1.bkp';
> +# get backup_id of the BACKUP operation. 
> +SELECT MAX(backup_id) FROM mysql.backup_history INTO @bid;
> +
> +# store VP time and binlog position
> +
> +SELECT validity_point_time FROM mysql.backup_history
> +WHERE backup_id = @bid INTO @vp_time;
> +SELECT binlog_file FROM mysql.backup_history
> +WHERE backup_id = @bid INTO @vp_file;
> +SELECT binlog_pos FROM mysql.backup_history
> +WHERE backup_id = @bid INTO @vp_pos;
> +
> +DROP DATABASE db1;
> +
> +# wait few seconds so that restore time != backup time
> +--sleep 2

[1]  I do not understand the purpose of sleep here.  Why does restore 
time have to be different from backup time.

> +
> +--replace_column 1 #
> +RESTORE FROM 'db1.bkp';
> +# determine id of RESTORE operation
> +SELECT MAX(backup_id) FROM mysql.backup_history INTO @bid;
> +
> +# check that VP info was correctly read and reported
> +
> +SELECT validity_point_time = @vp_time FROM mysql.backup_history
> +WHERE backup_id = @bid; 
> +SELECT binlog_file = @vp_file FROM mysql.backup_history
> +WHERE backup_id = @bid; 
> +SELECT binlog_pos = @vp_pos FROM mysql.backup_history
> +WHERE backup_id = @bid; 

[2] All three criteria could be checked with a single select statement.

> +
> +DROP DATABASE db1;
> +--remove_file $MYSQLTEST_VARDIR/master-data/db1.bkp
> +
> +
> +#
>  # This test is for the default and snapshot online backup drivers
>  #
>  
> 
> === modified file 'sql/backup/data_backup.cc'
> --- a/sql/backup/data_backup.cc	2008-10-30 20:02:15 +0000
> +++ b/sql/backup/data_backup.cc	2008-11-17 14:43:10 +0000
> @@ -412,6 +412,68 @@ int unblock_commits(THD *thd)
>  }
>  
>  /**
> +  Store information about validity point in @c Backup_info structure.
> +  
> +  @note This function is called in a time critical synchronization phase
> +  of the backup process. Therefore it should not perform any time consuming
> +  or potentially waiting operations such as I/O.
> +
> +  @returns 0 on success.
> +*/
> +static
> +int save_vp_info(Backup_info &info)
> +{
> +  LOG_INFO binlog_pos;
> +  int ret=0;
> +
> +  /*
> +    Save VP creation time.
> +  */
> +  info.save_vp_time(my_time(0));
> +
> +  /*
> +    Save current binlog position if it is enabled.
> +  */
> +  if (mysql_bin_log.is_open())
> +    if (mysql_bin_log.get_current_log(&binlog_pos))
> +    {
> +      info.m_ctx.report_error(ER_BACKUP_BINLOG);
> +      ret= TRUE;
> +    }
> +    else
> +      info.save_binlog_pos(binlog_pos);
> +
> +  /*
> +    Save master's binlog information if we are a connected slave.
> +  */
> +  if (obs::is_slave() && active_mi)
> +    info.save_master_pos(*active_mi);
> +
> +  return ret;
> +}
> +
> +/**
> +  Log validity point information.
> +
> +  Information such as validity point time is logged using backup logger which,
> +  in particular, writes it to backup history and progress logs.
> +  
> +  @note Logging the information may involve time consuming I/O. Therefore this
> +  function should not be called in the time critical synchronization phase, but
> +  after the synchronisation has been done.
> +*/ 
> +static
> +void report_vp_info(Backup_info &info)
> +{
> +  info.m_ctx.report_vp_time(info.get_vp_time(), TRUE); // TRUE = also write to
> progress log

[3] Line is too long.

> +  if (info.flags & BSTREAM_FLAG_BINLOG)
> +    info.m_ctx.report_binlog_pos(info.binlog_pos);
> +  if (info.master_pos.pos)
> +    info.m_ctx.report_master_binlog_pos(info.master_pos);
> +}
> +
> +
> +/**
>    Save data from tables being backed up.
>  
>    Function initializes and controls backup drivers which create the image
> @@ -424,8 +486,21 @@ int write_table_data(THD* thd, Backup_in
>  {
>    DBUG_ENTER("backup::write_table_data");
>  
> +  /*
> +    If there no tables to backup, there is nothing to do in this function
> +    except for storing and reporting the validity point info.
> +    
> +    Note that since backup image contains no table data, any time is a good
> +    validity time -- there is no issue of synchronizing the data stored in 
> +    the image with the data in the rest of the server.
> +  */ 
>    if (info.snap_count() == 0 || info.table_count() == 0) // nothing to backup
> -    DBUG_RETURN(0);
> +  {
> +    int res= save_vp_info(info);    // logs errors
> +    if (!res)
> +      report_vp_info(info);
> +    DBUG_RETURN(res);
> +  }
>  
>    Scheduler   sch(s, &info.m_ctx);          // scheduler instance
>    List<Scheduler::Pump>  inactive;  // list of images not yet being created
> @@ -433,8 +508,6 @@ int write_table_data(THD* thd, Backup_in
>    // keeps maximal init size for images in inactive list
>    size_t      max_init_size=0;
>  
> -  time_t      vp_time;              // to store validity point time
> -
>    DBUG_PRINT("backup_data",("initializing scheduler"));
>  
>    // add unknown "at end" drivers to scheduler, rest to inactive list
> @@ -582,8 +655,6 @@ int write_table_data(THD* thd, Backup_in
>      
>      DBUG_PRINT("backup_data",("-- SYNC PHASE --"));
>  
> -    LOG_INFO binlog_pos;
> -    
>      info.m_ctx.report_state(BUP_VALIDITY_POINT);
>      /*
>        This breakpoint is used to assist in testing state changes for
> @@ -600,33 +671,7 @@ int write_table_data(THD* thd, Backup_in
>      if (sch.lock())
>        goto error;
>  
> -    /*
> -      Save binlog information for point in time recovery on restore.
> -    */
> -    if (mysql_bin_log.is_open())
> -      if (mysql_bin_log.get_current_log(&binlog_pos))
> -      {
> -        info.m_ctx.fatal_error(ER_BACKUP_BINLOG);
> -        goto error;
> -      }
> -
> -    /*
> -      If we are a connected slave, write master's binlog information to
> -      the progress log for later use.
> -    */
> -    st_bstream_binlog_pos master_pos;
> -    master_pos.pos= 0;
> -    master_pos.file= 0;
> -    if (obs::is_slave() && active_mi)
> -    {
> -      master_pos.pos= (ulong)active_mi->master_log_pos;
> -      master_pos.file= active_mi->master_log_name;
> -    }
> -
> -    /*
> -      Save VP creation time.
> -    */
> -    vp_time= my_time(0);
> +    save_vp_info(info);
>  
>      DEBUG_SYNC(thd, "before_backup_data_unlock");
>      if (sch.unlock())
> @@ -640,23 +685,7 @@ int write_table_data(THD* thd, Backup_in
>      if (error)
>        goto error;
>  
> -    // Report and save information about VP
> -
> -    info.save_vp_time(vp_time);
> -    info.m_ctx.report_vp_time(vp_time, TRUE); // TRUE = also write to progress log
> -
> -    if (mysql_bin_log.is_open())
> -    {
> -      info.save_binlog_pos(binlog_pos);
> -      info.m_ctx.report_binlog_pos(info.binlog_pos);
> -    }
> -
> -    /*
> -      If we are a slave and the master's binlog position has been recorded
> -      write it to the log.
> -    */
> -    if (obs::is_slave() && master_pos.pos)
> -      info.m_ctx.report_master_binlog_pos(master_pos);
> +    report_vp_info(info);
>  
>      info.m_ctx.report_state(BUP_RUNNING);
>      DEBUG_SYNC(thd, "after_backup_binlog");
> @@ -1364,12 +1393,29 @@ namespace backup {
>   */
>  int restore_table_data(THD *thd, Restore_info &info, Input_stream &s)
>  {
> +  st_bstream_data_chunk chunk_info; // For reading chunks from the stream.
> +
>    DBUG_ENTER("restore::restore_table_data");
>  
>    enum { READING, SENDING, DONE, ERROR } state= READING;
>  
> +  /*
> +    If there are no tables stored in the image, there is nothing to do in this
> +    function. However, we must call bstream_rd_data_chunk() which will absorb
> +    the 0x00 byte signalling end of (the empty) table data chunk sequence.
> +  */ 
>    if (info.snap_count() == 0 || info.table_count() == 0) // nothing to restore
> +  {
> +    int res= bstream_rd_data_chunk(&s, &chunk_info);
> +    if (res != BSTREAM_EOC)
> +    {
> +       info.m_ctx.report_error(res == BSTREAM_ERROR ?
> +                                ER_BACKUP_READ_DATA :
> +                                ER_BACKUP_UNEXPECTED_DATA);
> +       DBUG_RETURN(ERROR);
> +    }
>      DBUG_RETURN(0);
> +  }
>  
>    Restore_driver* drv[256];
>  
> @@ -1426,8 +1472,6 @@ int restore_table_data(THD *thd, Restore
>  
>      // main data reading loop
>  
> -    st_bstream_data_chunk chunk_info;
> -
>      while ( state != DONE && state != ERROR )
>      {
>        switch (state) {
> 
> === modified file 'sql/backup/image_info.cc'
> --- a/sql/backup/image_info.cc	2008-11-05 09:41:15 +0000
> +++ b/sql/backup/image_info.cc	2008-11-17 14:43:10 +0000
> @@ -1,4 +1,5 @@
>  #include "../mysql_priv.h"
> +#include "../rpl_mi.h"
>  
>  #include "image_info.h"
>  #include "be_native.h"
> @@ -50,6 +51,7 @@ Image_info::Image_info()
>  #endif
>  
>    bzero(m_snap, sizeof(m_snap));
> +  bzero(&master_pos, sizeof(master_pos));
>  }
>  
>  Image_info::~Image_info()
> @@ -384,6 +386,14 @@ Image_info::Obj *find_obj(const Image_in
>    }
>  }
>  
> +void Image_info::save_master_pos(const ::Master_info &mi)
> +{
> +  // store binlog coordinates
> +  master_pos.pos=  static_cast<unsigned long int>(mi.master_log_pos);
> +  master_pos.file= const_cast<char*>(mi.master_log_name);
> +}
> +
> +
>  } // backup namespace
>  
>  template class Map<uint, backup::Image_info::Db>;
> 
> === modified file 'sql/backup/image_info.h'
> --- a/sql/backup/image_info.h	2008-11-05 09:41:15 +0000
> +++ b/sql/backup/image_info.h	2008-11-17 14:43:10 +0000
> @@ -75,6 +75,7 @@ public: // public interface
>     // info about image (most of it is in the st_bstream_image_header base
>  
>     size_t     data_size;      ///< How much of table data is saved in the image.
> +   st_bstream_binlog_pos  master_pos; ///< To store master position info.
>  
>     ulong      table_count() const;
>     uint       db_count() const;
> @@ -115,6 +116,7 @@ public: // public interface
>     void save_vp_time(const time_t time);   
>  
>     void save_binlog_pos(const ::LOG_INFO&);
> +   void save_master_pos(const ::Master_info&);
>  
>     time_t get_vp_time() const;
>  
> 
> === modified file 'sql/share/errmsg.txt'
> --- a/sql/share/errmsg.txt	2008-11-05 15:07:40 +0000
> +++ b/sql/share/errmsg.txt	2008-11-17 14:43:10 +0000
> @@ -6414,3 +6414,5 @@ ER_RESTORE_ON_SLAVE
>    eng "A restore operation was attempted on a slave during replication. You must
> stop the slave prior to running a restore."
>  ER_NONUNIQ_DB 42000 S1009
>          eng "Not unique database: '%-.192s'"
> +ER_BACKUP_UNEXPECTED_DATA
> +  eng "Backup image contains no tables, but table data was found in it"
> 
>