#At file:///home2/mydev/bzrroot/mysql-6.0-bug38133-3/
2740 Ingo Struewing 2008-11-21
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:
mysql-test/r/myisamlog_coverage.result
mysql-test/t/myisamlog_coverage-master.opt
mysql-test/t/myisamlog_coverage.test
modified:
mysql-test/t/myisamlog.test
storage/myisam/mi_close.c
storage/myisam/mi_examine_log.c
storage/myisam/myisamlog.c
per-file messages:
mysql-test/r/myisamlog_coverage.result
Bug#38133 - Myisamlog test fails on Windows
New test result.
mysql-test/t/myisamlog.test
Bug#38133 - Myisamlog test fails on Windows
Re-enabled the test case for Windows.
mysql-test/t/myisamlog_coverage-master.opt
Bug#38133 - Myisamlog test fails on Windows
New options file for new test case.
mysql-test/t/myisamlog_coverage.test
Bug#38133 - Myisamlog test fails on Windows
New test case.
storage/myisam/mi_close.c
Bug#38133 - Myisamlog test fails on Windows
Added DBUG.
storage/myisam/mi_examine_log.c
Bug#38133 - Myisamlog test fails on Windows
Added member lock_type to file_info.
Added ERROR_INJECT for coverage testing, available in debug build only.
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 error handling to the call to tree_insert().
Added kind of a "behavior prediction engine" before mi_lock_database()
for Windows to catch cases where the lock type changes.
Pulled close_some_files() out of reopen_closed_file() to have access
to max_files.
Added code to re-lock a file after re-open.
storage/myisam/myisamlog.c
Bug#38133 - Myisamlog test fails on Windows
Allowed for more of one (1!) file descriptor on platforms that
do not raise the maximum above the request.
Added DBUG.
=== 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-11-21 16:22:50 +0000
@@ -0,0 +1,134 @@
+DROP DATABASE IF EXISTS mysqltest;
+# CREATE generates no entry in the logical log.
+CREATE DATABASE mysqltest;
+USE mysqltest;
+CREATE TABLE t1 (c1 INT, c2 VARCHAR(100)) ENGINE=MyISAM;
+# Generate log entries.
+INSERT INTO t1 VALUES(1,'life'), (2,'file');
+INSERT INTO t1 SELECT c1*5, CONCAT("A ",c2) FROM t1;
+UPDATE t1 SET c2="A knife" WHERE c1=5;
+DELETE FROM t1 WHERE c1=10;
+SELECT * FROM t1;
+c1 c2
+1 life
+2 file
+5 A knife
+# Wipe it out (TRUNCATE generates no entry in the logical log).
+TRUNCATE TABLE t1;
+# Close the table (as we are going to change it outsid of the server).
+FLUSH TABLE t1;
+# Examine log.
+Commands Used count Errors Recover errors
+open 16 0 0
+write 4 0 0
+update 1 0 0
+delete 1 0 0
+close 8 0 0
+extra # 0 0
+lock 48 0 0
+Total # 0 0
+# Reopen the table and verify that it did not change.
+SELECT * FROM t1;
+c1 c2
+# Close the table (as we are going to change it outsid of the server).
+FLUSH TABLE t1;
+# Apply log to empty table.
+Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
+Tables updated successfully
+
+Commands Used count Errors Recover errors
+open 17 0 0
+write 4 0 0
+update 1 0 0
+delete 1 0 0
+close 9 0 0
+extra # 0 0
+lock 50 0 0
+Total # 0 0
+# Reopen the table and verify that content is back.
+SELECT * FROM t1;
+c1 c2
+1 life
+2 file
+5 A knife
+CHECK TABLE t1 EXTENDED;
+Table Op Msg_type Msg_text
+mysqltest.t1 check status OK
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at mi_examine_log_files0
+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
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at mi_examine_log_files1
+ERROR_INJECT("mi_examine_log_files1")
+Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
+Tables updated successfully
+
+Commands Used count Errors Recover errors
+open 18 0 0
+write 4 0 0
+update 1 0 0
+delete 1 0 0
+close 10 0 0
+extra # 0 0
+lock 54 0 0
+Total # 0 0
+Had to do 652 re-open because of too few possibly open files
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at mi_examine_log_command
+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'
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at close_some_file_none
+ERROR_INJECT("mi_examine_log_files1")
+ERROR_INJECT("close_some_file_none")
+Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
+Got error 22, expected 0 on command open at 87
+
+Commands Used count Errors Recover errors
+open 1 0 0
+extra # 0 0
+Total # 0 0
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at close_some_file_extra
+ERROR_INJECT("mi_examine_log_files1")
+ERROR_INJECT("close_some_file_extra")
+Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
+Got error 22, expected 0 on command lock at 259
+
+Commands Used count Errors Recover errors
+open 3 0 0
+extra # 0 0
+Total # 0 0
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at reopen_closed_file_name
+ERROR_INJECT("mi_examine_log_files1")
+ERROR_INJECT("reopen_closed_file_name")
+Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
+Got error 2, expected 0 on command re-open at 259
+
+Commands Used count Errors Recover errors
+open 3 0 0
+extra # 0 0
+Total # 0 0
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+# Inject error at close_some_file_lock_result
+ERROR_INJECT("close_some_file_lock_result")
+Trying to update MyISAM files according to log 'VARDIR/master-data/myisam.log'
+Got error 22, expected 1 on command lock at 259
+
+Commands Used count Errors Recover errors
+open 3 0 0
+extra # 0 0
+lock 1 0 0
+Total # 0 0
+DROP DATABASE mysqltest;
=== modified file 'mysql-test/t/myisamlog.test'
--- a/mysql-test/t/myisamlog.test 2008-07-15 20:02:29 +0000
+++ b/mysql-test/t/myisamlog.test 2008-11-21 16:22:50 +0000
@@ -3,11 +3,6 @@
--source include/not_embedded.inc
-#
-# This test fails on win platforms currently. See BUG#38133.
-#
---source include/not_windows.inc
-
disable_warnings;
create database if not exists mysqltest;
use mysqltest;
=== added file 'mysql-test/t/myisamlog_coverage-master.opt'
--- a/mysql-test/t/myisamlog_coverage-master.opt 1970-01-01 00:00:00 +0000
+++ b/mysql-test/t/myisamlog_coverage-master.opt 2008-11-21 16:22:50 +0000
@@ -0,0 +1 @@
+--log-isam
=== 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-11-21 16:22:50 +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).
+#
+--source include/have_nodebug.inc
+--source include/have_debug.inc
+#
+# Note that have_debug.inc is necessary for this test. Don't comment out.
+#
+
+--source include/not_embedded.inc
+
+--disable_warnings
+DROP DATABASE IF EXISTS mysqltest;
+--enable_warnings
+
+--echo # CREATE generates no entry in the logical log.
+CREATE DATABASE mysqltest;
+USE mysqltest;
+CREATE TABLE t1 (c1 INT, c2 VARCHAR(100)) ENGINE=MyISAM;
+#
+--echo # Generate log entries.
+INSERT INTO t1 VALUES(1,'life'), (2,'file');
+INSERT INTO t1 SELECT c1*5, CONCAT("A ",c2) FROM t1;
+UPDATE t1 SET c2="A knife" WHERE c1=5;
+DELETE FROM t1 WHERE c1=10;
+SELECT * FROM t1;
+#
+--echo # Wipe it out (TRUNCATE generates no entry in the logical log).
+TRUNCATE TABLE t1;
+--echo # Close the table (as we are going to change it outsid of the server).
+FLUSH TABLE t1;
+#
+--echo # Examine log.
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+exec $MYISAMLOG $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+--echo # Reopen the table and verify that it did not change.
+SELECT * FROM t1;
+--echo # Close the table (as we are going to change it outsid of the server).
+FLUSH TABLE t1;
+#
+--echo # Apply log to empty table.
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+exec $MYISAMLOG -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+--echo # Reopen the table and verify that content is back.
+SELECT * FROM t1;
+CHECK TABLE t1 EXTENDED;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at mi_examine_log_files0
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,mi_examine_log_files0 -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at mi_examine_log_files1
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+exec $MYISAMLOG -#d,mi_examine_log_files1 -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at mi_examine_log_command
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,mi_examine_log_command -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at close_some_file_none
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,close_some_file_none,mi_examine_log_files1 -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at close_some_file_extra
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,close_some_file_extra,mi_examine_log_files1 -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at reopen_closed_file_name
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,reopen_closed_file_name,mi_examine_log_files1 -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+TRUNCATE TABLE t1;
+FLUSH TABLE t1;
+--echo # Inject error at close_some_file_lock_result
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,close_some_file_lock_result -F $MYSQLTEST_VARDIR/master-data -u $MYSQLTEST_VARDIR/master-data/myisam.log 2>&1;
+#
+#
+# Cleanup.
+DROP DATABASE mysqltest;
=== modified file 'storage/myisam/mi_close.c'
--- a/storage/myisam/mi_close.c 2008-07-09 07:12:43 +0000
+++ b/storage/myisam/mi_close.c 2008-11-21 16:22:50 +0000
@@ -30,6 +30,7 @@ int mi_close(register MI_INFO *info)
DBUG_PRINT("enter",("base: %p reopen: %u locks: %u",
info, (uint) share->reopen,
(uint) share->tot_locks));
+ DBUG_PRINT("myisam", ("close '%s'", share->unresolv_file_name));
pthread_mutex_lock(&THR_LOCK_myisam);
if (info->lock_type == F_EXTRA_LCK)
=== 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-21 16:22:50 +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. */
ulong accessed;
};
@@ -85,6 +92,20 @@ struct st_access_param
#define NO_FILEPOS HA_OFFSET_ERROR
+/*
+ Error injection. Built on DBUG.
+ This is similar to error injection in the server.
+ In case that one becomes globally available, we undefine it first.
+*/
+#ifdef ERROR_INJECT
+#undef ERROR_INJECT
+#endif
+#define ERROR_INJECT(_keyword_, _action_) \
+ DBUG_EXECUTE_IF((_keyword_), \
+ fprintf(stderr, "ERROR_INJECT(\"%s\")\n", (_keyword_)); \
+ DBUG_PRINT("myisamlog", ("ERROR_INJECT(\"%s\")\n", \
+ (_keyword_))); _action_)
+
void mi_examine_log_param_init(MI_EXAMINE_LOG_PARAM *param);
int mi_examine_log(MI_EXAMINE_LOG_PARAM *param);
static int read_string(IO_CACHE *file,uchar* *to,uint length);
@@ -96,7 +117,7 @@ static int test_when_accessed(struct fil
struct st_access_param *access_param);
static void file_info_free(struct file_info *info);
static int close_some_file(TREE *tree);
-static int reopen_closed_file(TREE *tree,struct file_info *file_info);
+static int reopen_closed_file(struct file_info *file_info);
static int find_record_with_key(struct file_info *file_info,uchar *record);
static int mi_close_care_state(MI_INFO *info);
static void printf_log(uint verbose, ulong isamlog_process,
@@ -142,7 +163,7 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
int lock_command,mi_result;
char isam_file_name[FN_REFLEN], llbuff[21], llbuff2[21];
uchar head[20], *head_ptr;
- uchar *buff;
+ uchar *buff= NULL;
struct test_if_open_param open_param;
IO_CACHE cache;
File log_file;
@@ -155,6 +176,10 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
{ 11, 14 }, { 11, 14 }, { 9, 16 }, { 9, 16 }, { 7, 12 } };
uint has_pid_and_result[]= {1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0};
DBUG_ENTER("mi_examine_log");
+ DBUG_PRINT("myisamlog", ("max_files: %u update: %u",
+ mi_exl->max_files, mi_exl->update));
+ ERROR_INJECT("mi_examine_log_files0", mi_exl->max_files= 0;);
+ ERROR_INJECT("mi_examine_log_files1", mi_exl->max_files= 1;);
compile_time_assert((sizeof(mi_log_command_name) /
sizeof(mi_log_command_name[0]) ==
@@ -186,6 +211,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;
+
files_open=0; access_time=0;
while (access_time++ != mi_exl->number_of_commands &&
!my_b_read(&cache, head, 1))
@@ -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 */
+ fprintf(stderr,"Unknown command %u in logfile at position %s\n",
+ command, llstr(isamlog_filepos, llbuff));
+ fflush(stderr);
+ goto end;
+ /* purecov: end */
+ }
if (big_numbers != 0)
big_numbers= 1;
if (my_b_read(&cache, head, head_len[command][big_numbers] - 1))
@@ -219,24 +266,69 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
}
else
isamlog_process= file_info.process= result= 0;
+
+ /*
+ 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)))
{
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.
+ */
+ if (mi_exl->update && curr_file_info->used && curr_file_info->closed &&
+ (command != MI_LOG_CLOSE))
{
- if (reopen_closed_file(&tree,curr_file_info))
- {
- command=sizeof(mi_exl->com_count)/sizeof(mi_exl->com_count[0][0])/3;
- result=0;
- goto com_err;
- }
+ /* 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("close_some_file_extra", close_some_file(&tree););
+ if (close_some_file(&tree))
+ {
+ DBUG_PRINT("myisamlog", ("failed to close some file"));
+ goto com_err; /* No file to close */
+ }
+ files_open--;
+ }
+ if (reopen_closed_file(curr_file_info))
+ {
+ DBUG_PRINT("myisamlog", ("failed to reopen closed file"));
+ command=sizeof(mi_exl->com_count)/sizeof(mi_exl->com_count[0][0])/3;
+ result=0;
+ goto com_err;
+ }
+ files_open++;
mi_exl->re_open_count++;
+ /* purecov: end */
}
}
- DBUG_PRINT("info",("command: %u curr_file_info: 0x%lx used: %u",
- command, (ulong)curr_file_info,
- curr_file_info ? curr_file_info->used : 0));
+ if (!curr_file_info)
+ DBUG_PRINT("myisamlog",
+ ("command: %u '%s' info: 0x0",
+ command, mi_log_command_name[command]));
+ else
+ DBUG_PRINT("myisamlog",
+ ("command: %u '%s' info: 0x%lx proc: %ld "
+ "fno: %d file: '%s' used: %d closed: %d",
+ command, mi_log_command_name[command],
+ (ulong) curr_file_info, curr_file_info->process,
+ curr_file_info->filenr, curr_file_info->name,
+ curr_file_info->used, curr_file_info->closed));
/*
We update our statistic (how many commands issued, per command type),
if this is a valid command about a file we want to include.
@@ -259,9 +351,14 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
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 members should be non-null only during an open
+ 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 +427,15 @@ 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);
+ if (!tree_insert(&tree, (uchar*) &file_info, 0, tree.custom_arg))
+ {
+ /* tree_insert() (my_malloc()) should have written an error message. */
+ goto end; /* purecov: inspected */
+ }
+
if (file_info.used)
{
if (mi_exl->verbose && !mi_exl->record_pos_file)
@@ -342,6 +446,21 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
if (result)
mi_exl->com_count[command][1]++;
}
+
+ DBUG_PRINT("myisamlogop",
+ ("open proc: %ld fno: %d file: '%s' used: %d closed: %d",
+ file_info.process, file_info.filenr, file_info.name,
+ file_info.used, file_info.closed));
+ /*
+ 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;
break;
case MI_LOG_CLOSE:
if (mi_exl->verbose && !mi_exl->record_pos_file &&
@@ -352,6 +471,12 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
mi_log_command_name[command],result);
if (curr_file_info)
{
+ DBUG_PRINT("myisamlogop",
+ ("close proc: %ld fno: %d file: '%s' "
+ "used: %d closed: %d",
+ curr_file_info->process,
+ curr_file_info->filenr, curr_file_info->name,
+ curr_file_info->used, curr_file_info->closed));
if (!curr_file_info->closed)
files_open--;
(void) tree_delete(&tree, (uchar*) curr_file_info, 0, tree.custom_arg);
@@ -438,7 +563,6 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
head_ptr+= 4;
length= mi_uint2korr(head_ptr);
}
- buff=0;
if (read_string(&cache,&buff,length))
goto err;
if ((!mi_exl->record_pos_file ||
@@ -519,6 +643,7 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
}
}
my_free(buff,MYF(0));
+ buff= NULL;
break;
case MI_LOG_WRITE_BYTES_MYI:
case MI_LOG_WRITE_BYTES_MYD:
@@ -534,7 +659,6 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
head_ptr+= 4;
length= mi_uint2korr(head_ptr);
}
- buff=0;
if (read_string(&cache, &buff, length))
goto err;
if ((!mi_exl->record_pos_file ||
@@ -565,6 +689,7 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
goto com_err;
}
my_free(buff,MYF(0));
+ buff= NULL;
break;
case MI_LOG_CHSIZE_MYI:
/* here 'filepos' means new length of file */
@@ -607,11 +732,87 @@ 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;
+ DBUG_ASSERT(!curr_file_info->closed);
+ DBUG_PRINT("myisamlogop",
+ ("lock proc: %ld fno: %d file: '%s' lock_type: %d",
+ curr_file_info->process, curr_file_info->filenr,
+ curr_file_info->name, lock_command));
+#ifdef __WIN__
+ /*
+ my_lock() behaves differently on Windows than on UNIX-like
+ platforms. On Windows, a write lock can exist in parallel
+ to a read lock on the same file. Unlock does only remove
+ the latest acquired lock. On UNIX-like platforms, one lock
+ on a file replaces a former lock. After unlock there is no
+ lock remaining.
+
+ mi_lock_database has been modeled after the UNIX-like behavior.
+ For lock type changes it cally my_lock() with the new lock
+ type only. It does not release a pre-existing lock.
+
+ So we need to trick around the different system philosophies.
+ If you wonder about this quirky solution, please find the
+ review thread for Bug#38133 (Myisamlog test fails on Windows)
+ on commits@stripped.
+
+ Lock type changes (read->write or write->read) can normally
+ only happen when we try to unlock or write lock on top of
+ already existing locks. Unfortunately, mi_lock_database()
+ has the special capability to to turn a write lock to a
+ read lock on a request for a read lock if itself is the
+ owner of the only existing write lock. So we have to do
+ deeper checks if we have some lock on the share. We don't
+ need to exclude F_EXTRA_LCK as these won't appear in a
+ MyISAM log file.
+ */
+ if (curr_file_info->isam->s->tot_locks)
+ {
+ MYISAM_SHARE *share= curr_file_info->isam->s;
+ int ltype= curr_file_info->isam->lock_type;
+
+ /*
+ Unlock of an existing write lock can require a conversion
+ to a read lock. This happens if the current table instance
+ has the only remaining write lock and there are also read
+ locks on the share.
+
+ Write lock can require a conversion from a read lock.
+ This happens if there are read locks on the share, but no
+ write locks.
+
+ Read lock can require a conversion from a write lock.
+ This happens if the current table instance has the only
+ remaining write lock.
+ */
+ if (((lock_command == F_UNLCK) &&
+ (ltype == F_WRLCK) && (share->w_locks == 1) &&
+ share->r_locks) ||
+ ((lock_command == F_WRLCK) &&
+ share->r_locks && !share->w_locks) ||
+ ((lock_command == F_RDLCK) &&
+ (ltype == F_WRLCK) && (share->w_locks == 1)))
+ {
+ /*
+ One of the cases apply. We need to release the current
+ lock to avoid two locks on the same file.
+ */
+ if (my_lock(share->kfile, F_UNLCK, 0L, F_TO_EOF,
+ MYF(MY_WME | MY_SEEK_NOT_DONE)))
+ {
+ /* my_lock() should have written an error message. */
+ goto end;
+ }
+ }
+ }
+#endif
+ ERROR_INJECT("close_some_file_lock_result", result++;);
+ if (mi_lock_database(curr_file_info->isam,lock_command) !=
+ (int) result)
+ goto com_err; /* purecov: tested */
}
break;
case MI_LOG_DELETE_ALL:
@@ -635,6 +836,8 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
goto end;
}
}
+ DBUG_PRINT("myisamlog", ("end loop access_time: %lu cmd_cnt: %lu",
+ access_time, mi_exl->number_of_commands));
end_key_cache(dflt_key_cache,1);
delete_tree(&tree);
(void) end_io_cache(&cache);
@@ -643,25 +846,36 @@ int mi_examine_log(MI_EXAMINE_LOG_PARAM
DBUG_RETURN(1);
DBUG_RETURN(0);
+ /* purecov: begin inspected */
err:
fflush(stdout);
+ DBUG_PRINT("myisamlog", ("err label"));
fprintf(stderr,"Got error %d when reading from logfile\n",my_errno);
fflush(stderr);
goto end;
+ /* purecov: end */
+ /* purecov: begin tested */
com_err:
fflush(stdout);
+ DBUG_PRINT("myisamlog", ("com_err label"));
fprintf(stderr,"Got error %d, expected %d on command %s at %s\n",
my_errno,result,mi_log_command_name[command],
llstr(isamlog_filepos,llbuff));
fflush(stderr);
end:
+ DBUG_PRINT("myisamlog", ("end label"));
end_key_cache(dflt_key_cache, 1);
delete_tree(&tree);
(void) end_io_cache(&cache);
(void) my_close(log_file,MYF(0));
if (write_file)
(void) my_fclose(write_file,MYF(MY_WME));
+ my_free(file_info.name, MYF(MY_ALLOW_ZERO_PTR));
+ my_free(file_info.show_name, MYF(MY_ALLOW_ZERO_PTR));
+ my_free(file_info.record, MYF(MY_ALLOW_ZERO_PTR));
+ my_free(buff, MYF(MY_ALLOW_ZERO_PTR));
DBUG_RETURN(1);
+ /* purecov: end */
}
@@ -742,6 +956,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));
/* The 2 conditions below can be true only if 'update' */
if (!fileinfo->closed)
(void) mi_close_care_state(fileinfo->isam);
@@ -754,6 +970,7 @@ static void file_info_free(struct file_i
+/* purecov: begin tested */
static int close_some_file(TREE *tree)
{
struct st_access_param access_param;
@@ -763,8 +980,12 @@ static int close_some_file(TREE *tree)
(void) tree_walk(tree,(tree_walk_action) test_when_accessed,
(void*) &access_param,left_root_right);
+ ERROR_INJECT("close_some_file_none", access_param.found= 0;);
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));
if (mi_close_care_state(access_param.found->isam))
return 1;
access_param.found->closed=1;
@@ -772,21 +993,39 @@ 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>" */
+ ERROR_INJECT("reopen_closed_file_name", strcpy(name, "/non/existent/file"););
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 proc: %ld fno: %d file: '%s'",
+ (long) fileinfo, fileinfo->process,
+ fileinfo->filenr, fileinfo->name));
+ if (mi_lock_database(fileinfo->isam, fileinfo->lock_type))
+ DBUG_RETURN(1); /* --purecov: inspected */
+ }
+ DBUG_PRINT("myisamlog", ("re-opened info: 0x%lx lock_type: %d file: '%s'",
+ (long) fileinfo, fileinfo->lock_type,
+ fileinfo->name));
+ DBUG_RETURN(0);
}
+/* purecov: end */
/* Try to find record with uniq key */
=== modified file 'storage/myisam/myisamlog.c'
--- a/storage/myisam/myisamlog.c 2008-07-09 07:12:43 +0000
+++ b/storage/myisam/myisamlog.c 2008-11-21 16:22:50 +0000
@@ -59,8 +59,14 @@ int main(int argc, char **argv)
mi_exl.table_selection_hook= matches_list_of_tables;
}
- /* Number of MyISAM files we can have open at one time */
- mi_exl.max_files= (my_set_max_open_files(max(mi_exl.max_files,8))-6)/2;
+ /*
+ Despite its name, max_files is not the number of MyISAM files we can
+ have open at one time, but the number of MyISAM tables. Some
+ operating systems do not increase the limit above the input argument
+ of my_set_max_open_files(). So don't start too low.
+ */
+ mi_exl.max_files=
+ (my_set_max_open_files(max(mi_exl.max_files * 2, MY_NFILE)) - 6) / 2;
/*
Program must work in all conditions: support symbolic links.
@@ -75,6 +81,7 @@ int main(int argc, char **argv)
(mi_exl.recover ? "recover" : "update"),mi_exl.log_filename);
error= mi_examine_log(&mi_exl);
+ DBUG_PRINT("myisamlog", ("error from mi_examine_log: %d", error));
if (mi_exl.update && ! error)
puts("Tables updated successfully");
| Thread |
|---|
| • bzr commit into mysql-6.0-backup branch (ingo.struewing:2740) Bug#38133 | Ingo Struewing | 21 Nov |
