alfranio correia wrote:
> 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?
>
I've re-executed the tests with ndb enabled. Everything seems fine.
That's it.
Cheers.
>>
>>
>>> 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,
>>
>>
>>
>
>
>