Hello,
Ingo Struewing a écrit, Le 11/13/2008 09:55 AM:
> #At file:///home2/mydev/bzrroot/mysql-6.0-bug38133-2/
>
> 2730 Ingo Struewing 2008-11-13
> Bug#38133 - Myisamlog test fails on Windows
>
> Updating of a table from the myisam.log file was not possible in most cases.
> - The initialization of myisamlog set the number of usable file descriptors
> to one (1!) on Windows.
> - Every log command to a different file required a close of the previous file.
> After a 'close' command the closing of the previous file failed because
> all files were closed already and myisamlog stopped.
> - File locking on Windows failed for the sequence "exclusive lock, shared
> lock,
> unlock, exclusive lock". It blocked on the last try to acquire an exclusive
> lock.
>
> Fixed by
> - requesting a reasonable number of file descriptors,
> - before re-open, close a file only if all file descriptors are in use,
> - do not re-open a file, if the command is 'close',
> - unlock a file before every lock.
> per-file messages:
> mysys/my_lock.c
> Bug#38133 - Myisamlog test fails on Windows
> Added unlocking before locking to prevent multiple locks by the same process.
> sql/handler.cc
> Bug#38133 - Myisamlog test fails on Windows
> Changed abort() to DBUG_ABORT().
you could say why this change was needed.
> storage/myisam/mi_examine_log.c
> Bug#38133 - Myisamlog test fails on Windows
> Added member lock_type to file_info.
> Changed tracking of allocated memory in 'buff' and 'file_info' so that
> it can be freed in case of errors.
> Added a check for valid data in the log file.
> Disabled re-opening for a close command.
> Reduced closing of files to cases where file descriptors are used up.
> Added code to re-lock a file after re-open.
> Pulled close_some_files() out of reopen_closed_file() to have access
> to max_files.
> storage/myisam/mi_locking.c
> Bug#38133 - Myisamlog test fails on Windows
> Disabled locking for temporary tables that do not use F_EXTRA_LCK.
> Added DBUG.
> === modified file 'mysys/my_lock.c'
> --- a/mysys/my_lock.c 2008-09-12 12:57:19 +0000
> +++ b/mysys/my_lock.c 2008-11-13 08:55:37 +0000
> @@ -71,13 +71,23 @@ static int win_lock(File fd, int locktyp
> /* write lock is mapped to an exclusive lock. */
> dwFlags= LOCKFILE_EXCLUSIVE_LOCK;
>
> + /*
> + Drop old lock first to avoid double locking.
> + During analyze of Bug#38133 (Myisamlog test fails on Windows)
> + I met the situation that the program myisamlog locked the file
> + exclusively, then additionally shared, then did one unlock, and
> + then blocked on an attempt to lock it exclusively again.
> + Unlocking before every lock fixed the problem.
> + */
> + (void) UnlockFileEx(hFile, 0, liLength.LowPart, liLength.HighPart, &ov);
I'm anxious to have a fix like this which will in theory affect the
entire server, only to fix something exhibited by myisamlog, without
having a clear understanding of what is actually wrong (what module is
guilty).
When I read the comment above, my impression is that myisamlog is doing
something wrong:
- why lock shared if already has an exclusive lock?
- why re-lock exclusive if already has an exclusive lock?
It is "expected" that myisamlog does weird things: it's code which was
dead for >6 years, is very little tested in mysql-test, it may have old
bugs or new bugs due to other code's evolution. So I'd prefer if we dug
into myisamlog and fixed myisamlog than the server-wide locking code.
In other words, I believe the bug could be in the user of mysys
(myisamlog) more than in mysys. If the server didn't have any problem
with mysys of before-the-patch, given that the server is much more used
than myisamlog, I'd trust mysys more than myisamlog.
> === modified file 'storage/myisam/mi_examine_log.c'
> --- a/storage/myisam/mi_examine_log.c 2008-10-20 09:16:47 +0000
> +++ b/storage/myisam/mi_examine_log.c 2008-11-13 08:55:37 +0000
> @@ -69,6 +69,13 @@ struct file_info {
> my_bool closed;
> /** If this table matches the inclusion rules (or has to be ignored) */
> my_bool used;
> + /**
> + Lock type, set by last MI_LOG_LOCK command. Initialized to F_UNLCK
> + at MI_LOG_OPEN. This is not changed if the file is temporarily
> + closed. So it can be re-locked on re-open.
> + */
> + int lock_type;
> + /* File was last accessed at this log entry number. */
could use /** */
> ulong accessed;
> };
>
> @@ -186,6 +194,14 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> (void) init_key_cache(dflt_key_cache,KEY_CACHE_BLOCK_SIZE,KEY_CACHE_SIZE,
> 0, 0);
>
> + /*
> + Initialize members of file_info that are used for pointing to
> + allocated memory. At the error labels we want to be able to free it.
> + */
> + file_info.name= NULL;
> + file_info.show_name= NULL;
> + file_info.record= NULL;
A super-critical comment: you could have put all inits on one line:
file_info.name= file_info.show_name= file_info.record= NULL;
> files_open=0; access_time=0;
> while (access_time++ != mi_exl->number_of_commands &&
> !my_b_read(&cache, head, 1))
> @@ -194,6 +210,18 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> head_ptr= head;
> command=(uint) head_ptr[0];
> command-= (big_numbers= (command & MI_LOG_BIG_NUMBERS));
> + /*
> + 'command' is a number that is used to index arrays. Better check
> + it for range.
> + */
> + if (command >= MI_LOG_END_SENTINEL)
> + {
> + my_errno= HA_ERR_WRONG_COMMAND;
> + fprintf(stderr,"Unknown command %u in logfile at position %s\n",
> + command, llstr(isamlog_filepos, llbuff));
> + fflush(stderr);
> + goto end;
After "end:" we don't make use of my_errno, so no need to set it.
Or, set it, but use "goto err", in that case you can remove the
fflush(stderr).
> + }
> if (big_numbers != 0)
> big_numbers= 1;
> if (my_b_read(&cache, head, head_len[command][big_numbers] - 1))
> @@ -219,23 +247,64 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> }
> else
> isamlog_process= file_info.process= result= 0;
> +
> + DBUG_PRINT("myisamlog", ("command: %u '%s' process: %ld filenr: %d",
> + command, mi_log_command_name[command],
> + file_info.process, file_info.filenr));
> + /*
> + Try to find the file with file_info.process and file_info.filenr
> + in the file tree. The search function, as registered with
> + init_tree() is file_info_compare(). If the file does not exist in
> + the tree, most commands will be ignored for this file.
> + */
> if ((curr_file_info=(struct file_info*) tree_search(&tree, &file_info,
> tree.custom_arg)))
> {
> + DBUG_PRINT("myisamlog", ("found info: 0x%lx file: '%s' "
> + "used: %d closed: %d",
> + (long) curr_file_info, curr_file_info->name,
> + curr_file_info->used,
> curr_file_info->closed));
You can change 0x%lx to %p.
> curr_file_info->accessed=access_time;
> - if (mi_exl->update && curr_file_info->used &&
> curr_file_info->closed)
> + /*
> + If the file has been closed due to lack of file descriptors,
> + re-open it to execute the command.
> + No need to re-open for the MI_LOG_CLOSE command.
Ok, but you still go into "case MI_LOG_CLOSE" which is good as it does a
tree_delete(), which we don't want to skip.
> @@ -255,13 +324,19 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> }
> switch ((enum myisam_log_commands) command) {
> case MI_LOG_OPEN:
> + DBUG_PRINT("myisamlog", ("command MI_LOG_OPEN"));
I believe you don't need such line per command, because you already have:
DBUG_PRINT("info",("command: %u '%s' curr_file_info: 0x%lx used:
%u",
command, mi_log_command_name[command],
(ulong)curr_file_info,
curr_file_info ? curr_file_info->used : 0));
before the "switch".
> if (curr_file_info)
> printf("\nWarning: %s is opened with same process and filenumber\n"
> "Maybe you should use the -P option ?\n",
> curr_file_info->show_name);
> - file_info.name=0;
> - file_info.show_name=0;
> - file_info.record=0;
> + /*
> + These file_info memebers should be non-null only during an open
members
> + operation. Initially and after open they should be nulled.
> + That way we can free them in case of a jump to an error label.
> + */
> + DBUG_ASSERT(!file_info.name);
> + DBUG_ASSERT(!file_info.show_name);
> + DBUG_ASSERT(!file_info.record);
> length= big_numbers ? mi_uint4korr(head_ptr) : mi_uint2korr(head_ptr);
> if (read_string(&cache, (uchar **)&file_info.name, length))
> goto err;
> @@ -330,8 +405,19 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> goto end;
> files_open++;
> file_info.closed=0;
> + /* After explicit open, file is not locked. */
> + file_info.lock_type= F_UNLCK;
> }
> (void) tree_insert(&tree, (uchar*) &file_info, 0, tree.custom_arg);
interesting... we don't trap malloc failure here :(
> +
> + /*
> + tree_insert() copied file_info. Avoid that the allocated members
> + are freed while in use.
Could you please emphasize by writing:
"tree_insert() copied file_info (copied pointers)"
If not NULL-ed, they would not be freed while in use: the my_free() at
the end of the program would rather double-free them, because
file_info_free() (called via delete_tree()) would already have freed them.
> + */
> + file_info.name= NULL;
> + file_info.show_name= NULL;
> + file_info.record= NULL;
> +
> if (file_info.used)
> {
> if (mi_exl->verbose && !mi_exl->record_pos_file)
> @@ -595,6 +687,7 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> }
> break;
> case MI_LOG_LOCK:
> + DBUG_PRINT("myisamlog", ("command MI_LOG_LOCK"));
> length= big_numbers ? mi_uint4korr(head_ptr) : mi_uint2korr(head_ptr);
> DBUG_ASSERT(length == 4);
> if (my_b_read(&cache, head, length))
> @@ -607,14 +700,24 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
> printf_log(mi_exl->verbose, isamlog_process, isamlog_filepos,
> "%s: %s(%d) -> %d",FILENAME(curr_file_info),
> mi_log_command_name[command],lock_command,result);
> - if (mi_exl->update && curr_file_info &&
> !curr_file_info->closed)
> + if (mi_exl->update && curr_file_info)
> {
> - if (mi_lock_database(curr_file_info->isam,lock_command) !=
> - (int) result)
> - goto com_err;
> + /* Remember lock type for re-open. */
> + curr_file_info->lock_type= lock_command;
> + if (!curr_file_info->closed)
This is not something you changed, but normally when we come in "case
MI_LOG_LOCK" the table should be open (if it was closed due to shortage
of file descriptors, we would have reopened it before the "switch") so
could you please put a DBUG_ASSERT(!curr_file_info->closed) ?
> + {
> + DBUG_PRINT("myisamlog",
> + ("lock info: 0x%lx process: %ld filenr: %d file: '%s'",
> + (long) curr_file_info, curr_file_info->process,
> + curr_file_info->filenr, curr_file_info->name));
> + if (mi_lock_database(curr_file_info->isam,lock_command) !=
> + (int) result)
> + goto com_err;
> + }
> }
> break;
> @@ -742,6 +855,8 @@ static int test_when_accessed (struct fi
> static void file_info_free(struct file_info *fileinfo)
> {
> DBUG_ENTER("file_info_free");
> + DBUG_PRINT("myisamlog", ("freeing info: 0x%lx file: '%s'",
> + (long) fileinfo, fileinfo->name));
you could use %p
> /* The 2 conditions below can be true only if 'update' */
> if (!fileinfo->closed)
> (void) mi_close_care_state(fileinfo->isam);
> @@ -765,6 +880,9 @@ static int close_some_file(TREE *tree)
> (void*) &access_param,left_root_right);
> if (!access_param.found)
> return 1; /* No open file that is possibly to close */
> + DBUG_PRINT("myisamlog", ("closing info: 0x%lx file: '%s'",
> + (long) access_param.found,
> + access_param.found->name));
you could use %p
> if (mi_close_care_state(access_param.found->isam))
> return 1;
> access_param.found->closed=1;
> @@ -772,20 +890,35 @@ static int close_some_file(TREE *tree)
> }
>
>
> -static int reopen_closed_file(TREE *tree, struct file_info *fileinfo)
> +static int reopen_closed_file(struct file_info *fileinfo)
> {
> char name[FN_REFLEN];
> - if (close_some_file(tree))
> - return 1; /* No file to close */
> + DBUG_ENTER("reopen_closed_file");
> +
> strmov(name,fileinfo->show_name);
> if (fileinfo->id > 1)
> *strrchr(name,'<')='\0'; /* Remove "<id>" */
>
> if (!(fileinfo->isam= mi_open(name, O_RDWR,
> HA_OPEN_FOR_REPAIR | HA_OPEN_WAIT_IF_LOCKED)))
> - return 1;
> + DBUG_RETURN(1);
> fileinfo->closed=0;
> - return 0;
> + /*
> + If the file was explicitly locked when we needed to close it due to
> + lack of file descriptors, we re-lock it after re-open.
> + */
> + if (fileinfo->lock_type != F_UNLCK)
> + {
> + DBUG_PRINT("myisamlog",
> + ("lock info: 0x%lx process: %ld filenr: %d file: '%s'",
you could use %p
> + (long) fileinfo, fileinfo->process,
> + fileinfo->filenr, fileinfo->name));
> + (void) mi_lock_database(fileinfo->isam, fileinfo->lock_type);
why not catch errors here and return 1?
> + }
> + DBUG_PRINT("myisamlog", ("re-opened info: 0x%lx lock_type: %d file: '%s'",
you could use %p
> + (long) fileinfo, fileinfo->lock_type,
> + fileinfo->name));
> + DBUG_RETURN(0);
> }
>
> /* Try to find record with uniq key */
>
> === modified file 'storage/myisam/mi_locking.c'
> --- a/storage/myisam/mi_locking.c 2008-09-09 19:02:38 +0000
> +++ b/storage/myisam/mi_locking.c 2008-11-13 08:55:37 +0000
> @@ -104,7 +104,11 @@ int mi_lock_database(MI_INFO *info, int
> mi_print_error(share, HA_ERR_CRASHED);
> mi_mark_crashed(info);
> }
> - if (info->lock_type != F_EXTRA_LCK)
> + /*
> + If we have a pseudo lock (F_EXTRA_LCK) or a temporary table,
> + skip file locking.
> + */
> + if ((info->lock_type != F_EXTRA_LCK) && !share->temporary)
> {
> if (share->r_locks)
> { /* Only read locks left */
You explained that this change's reason was:
"I believe, I have seen cases where a temporary table did not take a
F_EXTRA_LCK lock. I want to prevent locking in this case too."
It is a desirable goal, but more of an optimization than a bug fix.
Also, normally, there should not be such cases: temporary tables should
always use F_EXTRA_LCK, like here:
int ha_myisam::external_lock(THD *thd, int lock_type)
{
file->in_use.data= thd;
return mi_lock_database(file, !table->s->tmp_table ?
lock_type : ((lock_type == F_UNLCK) ?
F_UNLCK : F_EXTRA_LCK));
}
There is this code at start of mi_lock_database():
if (lock_type == F_EXTRA_LCK) /* Used by TMP tables */
{
++share->w_locks;
++share->tot_locks;
info->lock_type= lock_type;
info->s->in_use= list_add(info->s->in_use, &info->in_use);
DBUG_RETURN(0);
}
I believe this is the optimized code which is intended for temporary
tables. If myisamlog does not pass F_EXTRA_LCK, it may be because it's a
too old program which needs some fixing. By the way, myisamlog should
not log anything about temporary tables at all.
I suggest to add
else
DBUG_ASSERT(!share->temporary);
to the if() block just above, run the tests and see what happens.
Another note: isn't it worrying that if short of file descriptors,
close_some_file() closes a file which may be locked? I hope that the
mi_close() code is ready for such awkward situation, but I'm not sure.
Maybe close_some_file() should, if appropriate, unlock the table before
closing it.
--
Mr. Guilhem Bichot <guilhem@stripped>
Sun Microsystems / MySQL, Lead Software Engineer
Bordeaux, France
www.sun.com / www.mysql.com
