#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:
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
mysys/my_lock.c
sql/handler.cc
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.
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() to get rid of pop-up windows.
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().
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-12-10 18:43:34 +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 mi_examine_log_close_extra
+ERROR_INJECT("mi_examine_log_files1")
+ERROR_INJECT("mi_examine_log_close_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 mi_examine_log_lock_result
+ERROR_INJECT("mi_examine_log_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
+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 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
+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-12-10 18:43:34 +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-12-10 18:43:34 +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-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).
+#
+--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 mi_examine_log_close_extra
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,mi_examine_log_close_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 mi_examine_log_lock_result
+--replace_result $MYSQLTEST_VARDIR VARDIR
+--replace_regex /extra......................../extra #/ /Total................/Total #/
+--error 1
+exec $MYISAMLOG -#d,mi_examine_log_lock_result -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 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;
+#
+#
+# Cleanup.
+DROP DATABASE mysqltest;
=== 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.
+ */
+ (void) UnlockFileEx(hFile, 0, liLength.LowPart, liLength.HighPart, &ov);
+
if (timeout_sec == WIN_LOCK_INFINITE)
{
if (LockFileEx(hFile, dwFlags, 0, liLength.LowPart, liLength.HighPart, &ov))
=== modified file 'sql/handler.cc'
--- a/sql/handler.cc 2008-11-06 18:46:03 +0000
+++ b/sql/handler.cc 2008-12-10 18:43:34 +0000
@@ -1113,7 +1113,8 @@ int ha_commit_trans(THD *thd, bool all)
uint rw_ha_count;
bool rw_trans;
- DBUG_EXECUTE_IF("crash_commit_before", abort(););
+ /* Use DBUG_ABORT() instead of abort() to avoid a pop-up on Windows. */
+ DBUG_EXECUTE_IF("crash_commit_before", DBUG_ABORT(););
/* Close all cursors that can not survive COMMIT */
if (is_real_trans) /* not a statement commit */
=== 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-12-10 18:43:34 +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-12-10 18:43:34 +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("mi_examine_log_close_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;
+ }
+ 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 */
}
- (void) tree_insert(&tree, (uchar*) &file_info, 0, tree.custom_arg);
+
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,19 @@ 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));
+ ERROR_INJECT("mi_examine_log_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 +768,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 +778,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 +888,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 +902,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 +912,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 +925,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-12-10 18:43:34 +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");
