I am unable to figure out what is causing this problem that is 100% reproducible on a 4.0.20-standard server. It works as follows:
1) Thread A locks InnoDB table Foo for writing SUCCESSFULLY. 2) Thread B locks InnoDB table Foo for writing, but has to wait for Thread A. 3) Thread A performs a query (I used "SELECT MAX(id) FROM foo;" for testing). 4) Thread A terminates the query with a "Lock wait timeout exceeded" error. 5) Thread B goes on its merry way.
NOTES:
1) NO OTHER THREADS are locking any of the tables in question or even have access to the databases in question
2) The THREAD WITH THE LOCK is the one that HAS THE ERROR
3) No other sequence of events seems to cause the problem
4) The lock on "foo" is not release until after Thread A either dies, disconnects or issues a LOCK/UNLOCK command
5) During the time that Thread A is performing the query, Thread B has a state of "Sending data" while Thread B is "Locked".
This only happens on the ISP's MySQL server (4.0.20-standard), not on our development server (4.1.7-standard). We do not have control over the system variables (except for runtime variables, of course). It only happens with InnoDB tables, not with MyISAM tables. I have included a perl script that causes the bug 100% of the time below. I can reproduce the bug using two instances of the mysql command-line utility and it manifests using PHP as well, so it's not a driver issue.
The innodb_lock_wait_timeout is set to the default 50 seconds, but this should NEVER be reached, as a query like "SELECT MAX(id) FROM foo;" should take less than 0.005 seconds.
Questions: Why is the query slowed when the process that is making it is the one that HAS the lock? And why does it happen only when another thread is trying to get a lock?
What can I do to get this working properly? I'm at my wit's end.
Since this is a large commercial ISP, I am unable to get them to upgrade MySQL because we have encoutered a bug.
Help, comments, suggestions, ridicule (accompanied by a remedy) actively solicited.
Thank you!
-Gabriele
--- START ENVIRONMENT INFO --- MySQL Server Version: 4.0.20-standard OS: Linux (Kernel 2.4.21-15.0.4.ELsmp) --- END ENVIRONMENT INFO ---
Perl Script that can reliably reproduce error:
--- START SCRIPT ---
#!/usr/bin/perl -w
use DBI;
use POSIX ":sys_wait_h";
use Time::HiRes qw( gettimeofday usleep tv_interval );
use strict;
$|=1;
# Catch dead forks.
sub REAPER {
my $c;
while (($c=waitpid(-1,WNOHANG))>0){
print "Proc $c died with \$? = '$?'\n";
}
$SIG{CHLD}=\&REAPER;
}
$SIG{CHLD}=\&REAPER;
my($u,$p) = (@ARGV);my $proc=0; my $step=0;
my $dbh=DBI->connect("DBI:mysql:database=test;host=localhost",
$u,$p, { PrintError=>1,PrintWarn=>1 });db_do("DROP TABLE IF EXISTS foo;");
db_do("CREATE TABLE foo ( id int ) TYPE=InnoDB ;");my $child_pid = fork(); die "Can't fork!" unless defined $child_pid;
$dbh=DBI->connect("DBI:mysql:database=test;host=localhost",
$u,$p, { PrintError=>1,PrintWarn=>1 });$step=0;
if($child_pid) {
$proc=1;
db_do("LOCK TABLES foo WRITE;");
usleep 5_000_000;
db_do("SELECT MAX(id) FROM foo;");
usleep 5_000_000;
db_do("UNLOCK TABLES;");
} else {
$proc=2;
usleep 1_500_000;
db_do("LOCK TABLES foo WRITE;");
db_do("UNLOCK TABLES;");
}
sub db_do {
my $sql = shift;
$step++;
my $t0=[gettimeofday];
$dbh->do($sql);
print "Process $proc, step $step: finish: ", $sql,
sprintf("%7.4f secs\n", tv_interval($t0));
}1; __END__ --- END SCRIPT ---
Script Output on 4.0.20 server: --- START OUTPUT --- Process 0, step 1: finish: DROP TABLE IF EXISTS foo; 0.1641 secs Process 0, step 2: finish: CREATE TABLE foo ( id int ) TYPE=InnoDB ; 0.0655 secs Process 1, step 1: finish: LOCK TABLES foo WRITE; 0.0010 secs DBD::mysql::db do failed: Lock wait timeout exceeded; Try restarting transaction at /home/divineme/test_locks line 53. Process 1, step 2: finish: SELECT MAX(id) FROM foo;51.6475 secs Process 1, step 3: finish: UNLOCK TABLES; 0.0003 secs Process 2, step 1: finish: LOCK TABLES foo WRITE;60.1304 secs Process 2, step 2: finish: UNLOCK TABLES; 0.0032 secs --- END OUTPUT ---
Script Ouput on 4.1.7 server: --- START OUTPUT --- Process 0, step 1: finish: DROP TABLE IF EXISTS foo; 0.0063 secs Process 0, step 2: finish: CREATE TABLE foo ( id int ) TYPE=InnoDB ; 0.0247 secs Process 1, step 1: finish: LOCK TABLES foo WRITE; 0.0003 secs Process 1, step 2: finish: SELECT MAX(id) FROM foo; 0.0003 secs Process 1, step 3: finish: UNLOCK TABLES; 0.0002 secs Process 2, step 1: finish: LOCK TABLES foo WRITE; 8.5087 secs Process 2, step 2: finish: UNLOCK TABLES; 0.0014 secs --- END OUTPUT ---
-- MySQL General Mailing List For list archives: http://lists.mysql.com/mysql To unsubscribe: http://lists.mysql.com/[EMAIL PROTECTED]
