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,
>
>