List:Commits« Previous MessageNext Message »
From:Andrei Elkin Date:March 15 2008 3:59pm
Subject:Re: bk commit into 5.0 tree (aelkin:1.2598) BUG#18199
View as plain text  
Sergey, hello.

Thanks for your good questions!

> Hi Andrei,
>
> On Fri, Mar 14, 2008 at 08:00:01PM +0200, Andrei Elkin wrote:
>> Below is the list of changes that have just been committed into a local
>> 5.0 repository of aelkin.  When aelkin does a push these changes
>> will be propagated to the main repository and, within 24 hours after the
>> push, to the public repository.
>> For information on how to access the public repository
>> see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html
>> 
>> ChangeSet@stripped, 2008-03-14 19:58:59+02:00, aelkin@mysql1000.(none) +5 -0
>>   Bug #18199  PURGE BINARY LOGS fails silently with missing logs;
>>   Bug #18453  Warning/error message if there is a mismatch between ...
>>    
>>   There were three problems:
>>    
>>    1. the reported lack of warnings for the BEFORE syntax of PURGE;
>>    2. the similar lack of warnings for the TO syntax;
>>    3. incompatible behaviour between the two in that the latter blanked out
>>       regardlessly of presence or lack the actual file corresponding to
>>       an index record; the former version gave up at the first mismatch.
>>   
>>   fixed with deploying the warning's generation and synronizing logics of 
>>   purge_logs() and purge_logs_before_date().
> ...skip...
>
>> --- /dev/null	Wed Dec 31 16:00:00 196900
>> +++ b/mysql-test/include/show_binary_logs.inc	2008-03-14 19:58:57 +02:00
>> +*** must be of one record in the index file after PURGE ***
>> +show binary logs;
>> +Log_name	File_size
>> +master-bin.000003	#
>> +master-bin.000004	#

> You claim that it must be of one record, but it is of two.

A typo calculation in the test, corrected. Added comments to explain
how many.

>
>> +reset master;
>> +flush logs;
>> +flush logs;
>> +flush logs;
>> +*** must be a warning master-bin.000001 was not found ***
>> +Warnings:
>> +Warning	1476	Being purged log MYSQLTEST_VARDIR/log/master-bin.000001 was not
> found
>> +*** must be of one record in the index file after PURGE ***
>> +show binary logs;
>> +Log_name	File_size
>> +master-bin.000004	#

> As far as I can see master-bin.000004 meets BEFORE condition. Why is it
> still here? 

a good question. The last log is the active

> Because it is a binary log we're writing to? If so, could you
> file documentation request, I didn't find anything relevant in our manual.

You seem to be right. The info pages say

   Deletes all the binary logs listed in the log index prior to the
   specified log or date.

It must be added

   s/./,/ ^

   except for the last log file if one is currently active.

I will suggest that.


>

>> diff -Nrup a/mysql-test/t/binlog_index.test b/mysql-test/t/binlog_index.test
>> --- /dev/null	Wed Dec 31 16:00:00 196900
>> +++ b/mysql-test/t/binlog_index.test	2008-03-14 19:58:57 +02:00
>> @@ -0,0 +1,49 @@
>> +#
>> +# testing of purging of binary log files bug#18199/Bug#18453
>> +#
>> +source include/have_log_bin.inc;
>> +source include/not_embedded.inc;
>> +
>> +#
>> +# testing purge binary logs TO
>> +#
>> +
>> +flush logs;
>> +flush logs;
>> +flush logs;
>> +
>> +--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
>> +--replace_column 2 #
>> +show binary logs;

> Why not to use show_binary_logs.inc here?

sure!

>
>> +remove_file $MYSQLTEST_VARDIR/log/master-bin.000001;
>> +
>> +# there must be a warning with file names
>> +--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
>> +purge binary logs TO 'master-bin.000003';
>> +
>> +--echo *** must be of one record in the index file after PURGE ***
>> +source include/show_binary_logs.inc;
>> +
>> +#
>> +# testing purge binary logs BEFORE
>> +#
>> +
>> +reset master;
>> +
>> +flush logs;
>> +flush logs;
>> +flush logs;
>> +remove_file $MYSQLTEST_VARDIR/log/master-bin.000001;
>> +
>> +--echo *** must be a warning master-bin.000001 was not found ***
>> +let $date=`select NOW()  +  INTERVAL 1 MINUTE`;
>> +--disable_query_log
>> +--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR

> Do you really need replace_result with query log disabled?
>

that's in order to hide non-determinstic time dependant statement.


>> +eval purge binary logs BEFORE '$date';
>> +--enable_query_log
>> +
>> +--echo *** must be of one record in the index file after PURGE ***
>> +source include/show_binary_logs.inc;
>> +
>> +--echo End of tests
>> diff -Nrup a/sql/log.cc b/sql/log.cc
>> --- a/sql/log.cc	2008-01-31 17:15:35 +02:00
>> +++ b/sql/log.cc	2008-03-14 19:58:57 +02:00
>> @@ -1209,16 +1209,15 @@ int MYSQL_LOG::purge_logs(const char *to
>>           !log_in_use(log_info.log_file_name))
>>    {
>>      ulong file_size= 0;
>> +    MY_STAT s, *lstat= my_stat(log_info.log_file_name, &s, MYF(0));
>>      if (decrease_log_space) //stat the file we want to delete
>>      {
>> -      MY_STAT s;
>> -
>>        /* 
>>           If we could not stat, we can't know the amount
>>           of space that deletion will free. In most cases,
>>           deletion won't work either, so it's not a problem.
>>        */
>> -      if (my_stat(log_info.log_file_name,&s,MYF(0)))
>> +      if (lstat)
>>          file_size= s.st_size;
>>        else
>>  	sql_print_information("Failed to execute my_stat on file '%s'",
>> @@ -1228,8 +1227,13 @@ int MYSQL_LOG::purge_logs(const char *to
>>        It's not fatal if we can't delete a log file ;
>>        if we could delete it, take its size into account
>>      */
>> +    if (!lstat)
>> +      push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
>> +                          ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
>> +                          log_info.log_file_name);
>>      DBUG_PRINT("info",("purging %s",log_info.log_file_name));
>> -    if (!my_delete(log_info.log_file_name, MYF(0)) &&
> decrease_log_space)
>> +    if ((lstat && !my_delete(log_info.log_file_name, MYF(0)))
>> +        && decrease_log_space)
>>        *decrease_log_space-= file_size;
>>      if (find_next_log(&log_info, 0) || exit_loop)
>>        break;

> Codewise this part is fine and I saw your point in reply to Mats, but:

> - there are some places in MySQL code, that check errno after my_delete(),
>   e.g. for ENOENT. Do you think they don't work (I'm not really sure, if
>   so, we're probably in a problem).
> - don't we need to report that we failed to remove log file for other than
>   ENOENT reason?

Although your questions are reasonable i think the old logics that did
not address your concern was robust enough.

Anyway, I added a test for an error returning by my_stat(). The
ENOENT error is only one that is benign, for other cases i think
purge_logs() should exit at once.
Secondly, I added a similar test for my_delete()'s error as well with
the same logics to tolerate only ENOENT (it can happen that a file is
deteted in between of successful my_stat() and my_delete()).
\footnote{ I don't like myself much merely a not that informative
`Fatal error during log purge' will show up on the user screen due to
non-ENOENT error in my_stat() or my_delete(). Still it's much better
than no distinguishing between creatical errors and the only ENOENT
non-critical error.
}

> - stat() may fail with different than ENOENT errno.
>

>> @@ -1286,11 +1290,19 @@ int MYSQL_LOG::purge_logs_before_date(ti
>>    while (strcmp(log_file_name, log_info.log_file_name) &&
>>  	 !log_in_use(log_info.log_file_name))
>>    {
>> -    /* It's not fatal even if we can't delete a log file */
>> -    if (!my_stat(log_info.log_file_name, &stat_area, MYF(0)) ||
>> -	stat_area.st_mtime >= purge_time)
>> -      break;
>> -    my_delete(log_info.log_file_name, MYF(0));
>> +    if (!my_stat(log_info.log_file_name, &stat_area, MYF(0)))
>> +    {
>> +      push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
>> +                          ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
>> +                          log_info.log_file_name);
>> +    }
>> +    else
>> +    {
>> +      if (stat_area.st_mtime >= purge_time)
>> +        break;
>> +      /* It's not fatal even if we can't delete a log file */
>> +      my_delete(log_info.log_file_name, MYF(0));
>> +    }
>>      if (find_next_log(&log_info, 0))
>>        break;
>>    }
> This hunk looks fine.
>
>> @@ -1300,7 +1312,7 @@ int MYSQL_LOG::purge_logs_before_date(ti
>>      the log index file after restart - otherwise, this should be safe
>>    */
>>    error= update_log_index(&log_info, 1);
>> -
>> +  
>>  err:
>>    pthread_mutex_unlock(&LOCK_index);
>>    DBUG_RETURN(error);
> This does not. :)

fixed

>
> Regards,
> Sergey
> -- 
> Sergey Vojtovich <svoj@stripped>
> MySQL AB, Software Engineer
> Izhevsk, Russia, www.mysql.com

A newer cset has been committed.

regards,

Andrei
Thread
bk commit into 5.0 tree (aelkin:1.2598) BUG#18199Andrei Elkin15 Mar
Re: bk commit into 5.0 tree (aelkin:1.2598) BUG#18199Andrei Elkin15 Mar