Re: bzr commit into mysql-6.0-backup branch (ingo.struewing:2740) Bug#38133

[Guilhem Bichot]

Hello Ingo,

Ingo Struewing a écrit, Le 12/10/2008 07:43 PM:
> #At file:///home2/mydev/bzrroot/mysql-6.0-bug38133-4/ based on
> revid:jorgen.loland@stripped
> 
>  2740 Ingo Struewing	2008-12-10
>       Bug#38133 - Myisamlog test fails on Windows
>       
>       Updating of a table from the myisam.log file was not possible in most cases
>       on Windows.
>       - 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 changing the lock type.

> === added file 'mysql-test/r/myisamlog_coverage.result'
> --- a/mysql-test/r/myisamlog_coverage.result	1970-01-01 00:00:00 +0000
> +++ b/mysql-test/r/myisamlog_coverage.result	2008-12-10 18:43:34 +0000

It is impressive to see so much testing of error conditions.
I remember some rule somewhere saying that all devs have to please dgcov 
(a.k.a. have good coverage of their push), my hat off to you for being 
one of the few (or maybe the only one) to honour this rule. It does give 
a feeling of confidence that you tested your work!!

> +ERROR_INJECT("mi_examine_log_files0")
> +Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
> +Got error 0, expected 0 on command open at 0

That message is confusing (a user could say: "got 0 - so what's wrong as 
it expected 0?") but anyway max_files=0 should never happen.

> +ERROR_INJECT("mi_examine_log_command")
> +Unknown command 11 in logfile at position 0
> +Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'

Here we have the stdout after stderr, unlike in previous test portions. 
This is a bit random, could you please add a fflush(stdout) before 
printing "Unknown command" to stderr?

> === added file 'mysql-test/t/myisamlog_coverage.test'
> --- a/mysql-test/t/myisamlog_coverage.test	1970-01-01 00:00:00 +0000
> +++ b/mysql-test/t/myisamlog_coverage.test	2008-12-10 18:43:34 +0000
> @@ -0,0 +1,128 @@
> +#
> +# Coverage testing of MyISAM logical logging and the myisamlog utility
> +#
> +
> +#
> +# NOTE: This test cannot run together with myisamlog.test.
> +# Both will run with one server process without restart.
> +# The myisam.log file is kept open over both test cases.
> +# myisamlog_coverage.test will append to the myisam.log file.
> +# This gives a different myisam.log file than when running
> +# myisamlog_coverage.test standalone.
> +# To prevent this from running automatiocally in the test suite,
> +# we have two contradicting requirements.
> +# If you want to run myisamlog_coverage.test standalone,
> +# comment out the next line (--source include/have_nodebug.inc).

We had the same problem with tests reading the Maria transaction log and 
expecting some content in them.
It's possible to have this test run by the testsuite all the time: in it,
- include some script which shuts down mysqld and tells mtr to not 
restart it yet
- remove_file the MyISAM log
- tell mtr to restart mysqld
- wait for it to be restarted, and start testing
(for an example: see suite/maria/t/maria-no-logging.test in the latest 
6.0-main, grab me on IRC if you need help).
This way you would have a deterministic myisam.log.

> +#
> +--source include/have_nodebug.inc
> +--source include/have_debug.inc

> === modified file 'mysys/my_lock.c'
> --- a/mysys/my_lock.c	2008-09-12 12:57:19 +0000
> +++ b/mysys/my_lock.c	2008-12-10 18:43:34 +0000
> @@ -71,6 +71,27 @@ 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.
> +    Note that this introduces a race condition. When the application
> +    wants to convert an exclusive lock into a shared one, it will now
> +    first unlock the file and then lock it shared. A waiting exclusive
> +    lock could step in here. For reasons described in Bug#38133 and
> +    Bug#41124 (Server hangs on Windows with --external-locking after
> +    INSERT...SELECT) and in the review thread at
> +    http://lists.mysql.com/commits/60721 it seems to be the better
> +    option than not to unlock here.
> +    If one day someone notices a way how to do file lock type changes
> +    on Windows without unlocking before taking the new lock, please
> +    change this code accordingly to fix the race condition.

If not already done, could you please check with our Windows warriors 
(like Wlad) if they know such a way?

> +  */
> +  (void) UnlockFileEx(hFile, 0, liLength.LowPart, liLength.HighPart, &ov);

So here we want to ignore errors of UnlockFileEx. If we nit-pick, it's 
only ERROR_NOT_LOCKED which we want to ignore, like is done a few lines 
earlier in this file:
   if (locktype == F_UNLCK)
   {
     if (UnlockFileEx(hFile, 0, liLength.LowPart, liLength.HighPart, &ov))
       DBUG_RETURN(0);
     /*
       For compatibility with fcntl implementation, ignore error,
       if region was not locked
     */
     if (GetLastError() == ERROR_NOT_LOCKED)
     {
       SetLastError(0);
       DBUG_RETURN(0);
     }

You are free to choose if you want to do the same for the added 
UnlockFileEx() or not.

> === 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-12-10 18:43:34 +0000

> @@ -194,6 +227,20 @@ 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.
> +    */
> +    ERROR_INJECT("mi_examine_log_command", command= MI_LOG_END_SENTINEL;);
> +    if (command >= MI_LOG_END_SENTINEL)
> +    {
> +      /* purecov: begin tested */

if you enable myisamlog-coverage.test, you can remove several purecov 
markers accross the file.

> @@ -219,24 +266,69 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM 

> +        /* purecov: begin tested */
> +        /*
> +          We found a closed file. It can only be closed due to a lack
> +          of file descriptors. When a file is explicitly closed, its
> +          information is removed from the tree and freed.
> +          But this does not mean that there are still open files in
> +          the tree. All other files could have been explicitly closed
> +          meanwhile. So close a file only if there is still a lack of
> +          file descriptors.
> +        */
> +        if (files_open >= mi_exl->max_files)
> +        {
> +          ERROR_INJECT("mi_examine_log_close_extra", close_some_file(&tree););

I don't understand what you want to test with this one; it 
desynchronizes files_open with the actual number of open/closed files...?

> +          if (close_some_file(&tree))
> +          {
> +            DBUG_PRINT("myisamlog", ("failed to close some file"));
> +            goto com_err; /* No file to close */
> +          }
> +          files_open--;
> +        }

Ok to push. You don't need a new review after fixing the little issues 
or answering my questions.
Thanks for your patience in this long review cycle.

-- 
Mr. Guilhem Bichot <guilhem@stripped>
Sun Microsystems / MySQL, Lead Software Engineer
Bordeaux, France
www.sun.com / www.mysql.com