List:Commits« Previous MessageNext Message »
From:alfranio correia Date:November 17 2008 10:23am
Subject:Re: bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826
Bug#39325
View as plain text  
Andrei Elkin wrote:
> Luis, Alfranio, hello!
>
> I have a few comments on this work.
> The patch is basically okay with me.
>
>
>   
>> #At file:///stuff/workspace/mysql-server/bugfix/5.1-rpl-38826-39325/
>>
>>  2690 Luis Soares	2008-11-04
>>       This is a combined patch for: BUG#38826 and BUG#39325.
>>       It merges the previous two proposed patches into a single one.
>>             
>>     
>
> Please add the problem description and the solution sections
> into the top level change set comments. This is a requirement for all
> patches.
> Considering other requirements, such as the coding style there are few 
> assignments "x = " (which I personally prefer) instead of the required
> "x= ", could you please fix that?
>   
Sorry for that.

> There is no specific test although lines like
>   
>> +  DBUG_EXECUTE_IF("crash_before_flush_relay_log_info", abort(););
>>     
> makes me think we can have some.
>   
We have something, we will publish today or in the worst case tomorrow.
>   
>>       
>>       The difference from previous patch is that it calls 
>>       "ha_binlog_index_purge_file" before purging the relay log
>>       file.
>>     
>
> As I asked on #rep on Fri about if rpl_ndb had passed, could you
> please confirm they have done or if there are some issues still (then
> what kind of?).
>   

I haven't had the rpl_ndb enabled but I can re-run the tests.
I've asked the ndb team to take a look at the patch because their engine
receives
a notification when a log file is deleted but there is no description on
the expected semantics, etc, etc.
So I was wondering if the patch does not break anything.
Even if I re-run the tests with ndb enabled, I think they should take a
look at the patch.
Luis, do you want me to re-run the tests?
>
>   
>> modified:
>>   mysql-test/suite/binlog/r/binlog_index.result
>>   sql/log.cc
>>   sql/log.h
>>
>> === modified file 'mysql-test/suite/binlog/r/binlog_index.result'
>> --- a/mysql-test/suite/binlog/r/binlog_index.result	2008-04-05 11:09:53 +0000
>> +++ b/mysql-test/suite/binlog/r/binlog_index.result	2008-11-04 12:20:59 +0000
>> @@ -21,6 +21,7 @@ flush logs;
>>  *** must be a warning master-bin.000001 was not found ***
>>  Warnings:
>>  Warning	1612	Being purged log master-bin.000001 was not found
>> +Warning	1612	Being purged log master-bin.000001 was not found
>>  *** must show one record, of the active binlog, left in the index file after
> PURGE ***
>>  show binary logs;
>>  Log_name	File_size
>>
>> === modified file 'sql/log.cc'
>> --- a/sql/log.cc	2008-10-23 19:27:09 +0000
>> +++ b/sql/log.cc	2008-11-04 12:20:59 +0000
>> @@ -2358,6 +2358,7 @@ MYSQL_BIN_LOG::MYSQL_BIN_LOG()
>>    */
>>    index_file_name[0] = 0;
>>    bzero((char*) &index_file, sizeof(index_file));
>> +  bzero((char*) &purge_temp, sizeof(purge_temp));
>>  }
>>  
>>  /* this is called only once */
>> @@ -2918,10 +2919,11 @@ err:
>>  
>>    IMPLEMENTATION
>>    - Protects index file with LOCK_index
>> +  - Read the next file name from the index file and store in rli->linfo
>>    - Delete relevant relay log files
>>    - Copy all file names after these ones to the front of the index file
>>    - If the OS has truncate, truncate the file, else fill it with \n'
>> -  - Read the next file name from the index file and store in rli->linfo
>> +
>>  
>>    @param rli	       Relay log information
>>    @param included     If false, all relay logs that are strictly before
>> @@ -2952,6 +2954,7 @@ err:
>>  int MYSQL_BIN_LOG::purge_first_log(Relay_log_info* rli, bool included)
>>  {
>>    int error;
>> +  char *to_purge_if_included = NULL;
>>    DBUG_ENTER("purge_first_log");
>>  
>>    DBUG_ASSERT(is_open());
>> @@ -2959,36 +2962,20 @@ int MYSQL_BIN_LOG::purge_first_log(Relay
>>   
> DBUG_ASSERT(!strcmp(rli->linfo.log_file_name,rli->event_relay_log_name));
>>  
>>    pthread_mutex_lock(&LOCK_index);
>> -  pthread_mutex_lock(&rli->log_space_lock);
>> -  rli->relay_log.purge_logs(rli->group_relay_log_name, included,
>> -                            0, 0, &rli->log_space_total);
>> -  // Tell the I/O thread to take the relay_log_space_limit into account
>> -  rli->ignore_log_space_limit= 0;
>> -  pthread_mutex_unlock(&rli->log_space_lock);
>> +  to_purge_if_included = my_strdup(rli->group_relay_log_name, MYF(0));
>>  
>>    /*
>> -    Ok to broadcast after the critical region as there is no risk of
>> -    the mutex being destroyed by this thread later - this helps save
>> -    context switches
>> -  */
>> -  pthread_cond_broadcast(&rli->log_space_cond);
>> -  
>> -  /*
>>      Read the next log file name from the index file and pass it back to
>> -    the caller
>> -    If included is true, we want the first relay log;
>> -    otherwise we want the one after event_relay_log_name.
>> -  */
>> -  if ((included && (error=find_log_pos(&rli->linfo, NullS, 0)))
> ||
>> -      (!included &&
>> -       ((error=find_log_pos(&rli->linfo, rli->event_relay_log_name,
> 0)) ||
>> -        (error=find_next_log(&rli->linfo, 0)))))
>> +    the caller.
>> +  */
>> +  if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0))
> || 
>> +     (error=find_next_log(&rli->linfo, 0)))
>>    {
>>      char buff[22];
>>      sql_print_error("next log error: %d  offset: %s  log: %s included: %d",
>>                      error,
>>                      llstr(rli->linfo.index_file_offset,buff),
>> -                    rli->group_relay_log_name,
>> +                    rli->event_relay_log_name,
>>                      included);
>>      goto err;
>>    }
>> @@ -3013,10 +3000,48 @@ int MYSQL_BIN_LOG::purge_first_log(Relay
>>      rli->notify_group_relay_log_name_update();
>>    }
>>  
>> +  DBUG_EXECUTE_IF("crash_before_flush_relay_log_info", abort(););
>> +
>>    /* Store where we are in the new file for the execution thread */
>>    flush_relay_log_info(rli);
>>  
>> +  DBUG_EXECUTE_IF("crash_before_purge_logs", abort(););
>>     
>
> Could you please make a test that confirms the correct execution
> happens despite of the simulated failures?
>   

Of course. Answer above ;) ^^
>
>   
>> +
>> +  pthread_mutex_lock(&rli->log_space_lock);
>> +  rli->relay_log.purge_logs(to_purge_if_included, included,
>> +                            0, 0, &rli->log_space_total);
>> +  // Tell the I/O thread to take the relay_log_space_limit into account
>> +  rli->ignore_log_space_limit= 0;
>> +  pthread_mutex_unlock(&rli->log_space_lock);
>> +
>> +  /*
>> +    Ok to broadcast after the critical region as there is no risk of
>> +    the mutex being destroyed by this thread later - this helps save
>> +    context switches
>> +  */
>> +  pthread_cond_broadcast(&rli->log_space_cond);
>> +
>>     
>
>   
>> +  /*
>> +   * Need to update the log pos because purge logs has been called 
>> +   * after fetching initially the log pos at the begining of the method.
>> +   */
>> +  if(error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0))
>> +  {
>> +    char buff[22];
>> +    sql_print_error("next log error: %d  offset: %s  log: %s included: %d",
>> +                    error,
>> +                    llstr(rli->linfo.index_file_offset,buff),
>> +                    rli->group_relay_log_name,
>> +                    included);
>> +    goto err;
>> +  }
>>     
>
> I wonder if we really need to call `find_next_log()' at this point.
> How about to force `MYSQL_BIN_LOG::purge_logs()' to validate
> correctness of playing around with the logs and the index 
> with `find_log_pos()' at the end of the method?
> I.e  if `include' is false then `purge_logs(to_purge_if_included,
> included...)' must find `to_purge_if_included', otherwise 
> `find_log_pos(&rli->linfo, 0, 0)' should not return an error.
>
>
>
>   
Not following you here... I will take a look at the code
and drop a few comments later on.
>   
>> +
>> +  /* If included was passed, rli->linfo should be the first entry. */
>> +  DBUG_ASSERT(!included || rli->linfo.index_file_start_offset == 0);
>> +
>> +
>>  err:
>> +  my_free(to_purge_if_included, MYF(0));
>>    pthread_mutex_unlock(&LOCK_index);
>>    DBUG_RETURN(error);
>>  }
>> @@ -3076,8 +3101,37 @@ int MYSQL_BIN_LOG::purge_logs(const char
>>  
>>    if (need_mutex)
>>      pthread_mutex_lock(&LOCK_index);
>> -  if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/)))
>> +
>> +  if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/))) 
>> +  {
>> +    sql_print_error("MYSQL_LOG::purge_logs was called with file %s not "
>> +                    "listed in the index.", to_log);
>>      goto err;
>> +  }
>> +
>> +  /*
>> +    For crash recovery reasons the index needs to be updated before
>> +    any files are deleted. Move files to be deleted into a temp file
>> +    to be processed after the index is updated.
>> +  */
>> +  if (!my_b_inited(&purge_temp))
>> +  {
>> +    if (error=open_cached_file(&purge_temp, mysql_tmpdir, TEMP_PREFIX,
>> +                               DISK_BUFFER_SIZE, MYF(MY_WME)))
>> +    {
>> +      sql_print_error("MYSQL_LOG::purge_logs failed to open purge_temp");
>> +      goto err;
>> +    }
>> +  }
>> +  else
>> +  {
>> +    if (error=reinit_io_cache(&purge_temp, WRITE_CACHE, 0, 0, 1))
>> +    {
>> +      sql_print_error("MYSQL_LOG::purge_logs failed to reinit purge_temp "
>> +                      "for write");
>> +      goto err;
>> +    }
>> +  }
>>  
>>    /*
>>      File name exists in index file; delete until we find this file
>> @@ -3088,6 +3142,61 @@ int MYSQL_BIN_LOG::purge_logs(const char
>>    while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included))
> &&
>>           !log_in_use(log_info.log_file_name))
>>    {
>> +    if ((error=my_b_write(&purge_temp, (const
> uchar*)log_info.log_file_name,
>> +                          strlen(log_info.log_file_name))) ||
>> +        (error=my_b_write(&purge_temp, (const uchar*)"\n", 1)))
>> +    {
>> +      sql_print_error("MYSQL_LOG::purge_logs failed to copy %s to purge_temp",
>> +                      log_info.log_file_name);
>> +      goto err;
>> +    }
>> +
>> +    if (find_next_log(&log_info, 0) || exit_loop)
>> +      break;
>> + }
>> +
>> +  /* We know how many files to delete. Update index file. */
>> +  if (error=update_log_index(&log_info, need_update_threads))
>> +  {
>> +    sql_print_error("MSYQL_LOG::purge_logs failed to update the index file");
>> +    goto err;
>> +  }
>> +
>> +  DBUG_EXECUTE_IF("crash_after_update_index", abort(););
>> +
>> +  /* Switch purge_temp for read. */
>> +  if (error=reinit_io_cache(&purge_temp, READ_CACHE, 0, 0, 0))
>> +  {
>> +    sql_print_error("MSYQL_LOG::purge_logs failed to reinit purge_temp "
>> +                    "for read");
>> +    goto err;
>> +  }
>> +
>> +  /* Read each entry from purge_temp and delete the file. */
>> +  for (;;)
>> +  {
>> +    uint length;
>> +
>> +    if ((length=my_b_gets(&purge_temp, log_info.log_file_name,
>> +                          FN_REFLEN)) <= 1)
>> +    {
>> +      if (purge_temp.error)
>> +      {
>> +        error= purge_temp.error;
>> +        sql_print_error("MSYQL_LOG::purge_logs error %d reading from "
>> +                        "purge_temp", error);
>> +        goto err;
>> +      }
>> +
>> +      /* Reached EOF */
>> +      break;
>> +    }
>> +
>> +    /* Get rid of the trailing '\n' */
>> +    log_info.log_file_name[length-1]= 0;
>> +
>> +    ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
>> +
>>      MY_STAT s;
>>      if (!my_stat(log_info.log_file_name, &s, MYF(0)))
>>      {
>> @@ -3188,22 +3297,8 @@ int MYSQL_BIN_LOG::purge_logs(const char
>>          }
>>        }
>>      }
>> -
>> -    ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
>> -
>> -    if (find_next_log(&log_info, 0) || exit_loop)
>> -      break;
>>    }
>>    
>> -  /*
>> -    If we get killed -9 here, the sysadmin would have to edit
>> -    the log index file after restart - otherwise, this should be safe
>> -  */
>> -  error= update_log_index(&log_info, need_update_threads);
>> -  if (error == 0) {
>> -    error = ret;
>> -  }
>> -
>>  err:
>>    if (need_mutex)
>>      pthread_mutex_unlock(&LOCK_index);
>> @@ -3214,8 +3309,7 @@ err:
>>    Remove all logs before the given file date from disk and from the
>>    index file.
>>  
>> -  @param thd		Thread pointer
>> -  @param before_date	Delete all log files before given date.
>> +  @param purge_time	Delete all log files before given date.
>>  
>>    @note
>>      If any of the logs before the deleted one is in use,
>> @@ -3232,6 +3326,7 @@ err:
>>  int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time)
>>  {
>>    int error;
>> +  char to_log[FN_REFLEN];
>>    LOG_INFO log_info;
>>    MY_STAT stat_area;
>>    THD *thd= current_thd;
>> @@ -3240,11 +3335,8 @@ int MYSQL_BIN_LOG::purge_logs_before_dat
>>  
>>    pthread_mutex_lock(&LOCK_index);
>>  
>> -  /*
>> -    Delete until we find curren file
>> -    or a file that is used or a file
>> -    that is older than purge_time.
>> -  */
>> +  to_log[0] = 0;
>> +
>>    if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
>>      goto err;
>>  
>> @@ -3294,55 +3386,19 @@ int MYSQL_BIN_LOG::purge_logs_before_dat
>>      }
>>      else
>>      {
>> -      if (stat_area.st_mtime >= purge_time)
>> -        break;
>> -      if (my_delete(log_info.log_file_name, MYF(0)))
>> -      {
>> -        if (my_errno == ENOENT) 
>> -        {
>> -          /* It's not fatal even if we can't delete a log file */
>> -          if (thd)
>> -          {
>> -            push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
>> -                                ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
>> -                                log_info.log_file_name);
>> -          }
>> -          sql_print_information("Failed to delete file '%s'",
>> -                                log_info.log_file_name);
>> -          my_errno= 0;
>> -        }
>> -        else
>> -        {
>> -          if (thd)
>> -          {
>> -            push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_ERROR,
>> -                                ER_BINLOG_PURGE_FATAL_ERR,
>> -                                "a problem with deleting %s; "
>> -                                "consider examining correspondence "
>> -                                "of your binlog index file "
>> -                                "to the actual binlog files",
>> -                                log_info.log_file_name);
>> -          }
>> -          else
>> -          {
>> -            sql_print_information("Failed to delete log file '%s'",
>> -                                  log_info.log_file_name); 
>> -          }
>> -          error= LOG_INFO_FATAL;
>> -          goto err;
>> -        }
>> +      if(stat_area.st_mtime < purge_time)  {
>> +         strmake(to_log, 
>> +                 log_info.log_file_name, 
>> +                 sizeof(log_info.log_file_name));
>>        }
>> -      ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
>> +      else
>> +        break;
>>      }
>>      if (find_next_log(&log_info, 0))
>>        break;
>>    }
>>  
>> -  /*
>> -    If we get killed -9 here, the sysadmin would have to edit
>> -    the log index file after restart - otherwise, this should be safe
>> -  */
>> -  error= update_log_index(&log_info, 1);
>> +  error = (to_log[0] ? purge_logs(to_log, 1, 0, 1, (ulonglong *) 0) : 0);
>>     
>
> This looks to me as a very ellegant approach to redefine
> the before through the most generic method. Thanks for making it!
>   
Just doing the job ;).
>   
>>  
>>  err:
>>    pthread_mutex_unlock(&LOCK_index);
>>
>> === modified file 'sql/log.h'
>> --- a/sql/log.h	2008-10-06 08:27:36 +0000
>> +++ b/sql/log.h	2008-11-04 12:20:59 +0000
>> @@ -233,6 +233,15 @@ class MYSQL_BIN_LOG: public TC_LOG, priv
>>    pthread_cond_t update_cond;
>>    ulonglong bytes_written;
>>    IO_CACHE index_file;
>> +
>> +  /*
>> +    purge_temp is a temp file used in purge_logs so that the index file
>> +    can be updated before deleting files from disk, yielding better crash
>> +    recovery. It is created on demand the first time purge_logs is called
>> +    and then reused for subsequent calls. It is cleaned up in cleanup().
>> +  */
>> +  IO_CACHE purge_temp;
>> +
>>    char index_file_name[FN_REFLEN];
>>    /*
>>       The max size before rotation (usable only if log_type == LOG_BIN: binary
>>
>>
>> -- 
>> MySQL Code Commits Mailing List
>> For list archives: http://lists.mysql.com/commits
>> To unsubscribe:    http://lists.mysql.com/commits?unsub=1
>>
>>     
>
> cheers,
>
>   

Thread
bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826 Bug#39325Luis Soares4 Nov
  • Re: bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826Bug#39325alfranio correia4 Nov
  • Re: bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826 Bug#39325Andrei Elkin17 Nov
    • Re: bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826Bug#39325Luís Soares4 Dec
Re: bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826Bug#39325alfranio correia17 Nov
  • Re: bzr commit into mysql-5.1 branch (luis.soares:2690) Bug#38826Bug#39325alfranio correia29 Nov