From d09ed4e08ce6dfeba6caf239e4649cdcd2c69b9d Mon Sep 17 00:00:00 2001 From: Matthias Leich Date: Fri, 7 Jan 2011 14:16:28 +0100 Subject: [PATCH] Fix for Bug#47745 innodb.innodb-timeout fails sporadically - Second scenario checked: Ensure via wait routines that the commit comes after the processing of the statement which should get finally the ER_LOCK_WAIT_TIMEOUT --> This should prevent the current bug. - First scenario checked: Ensure via wait routines that the statement is already waiting for getting the lock before the commit is given. --> No effect on the current bug, but ensure that the right scenario is reached. - Take care that disconnects are finished before the test ends. --> Reduce the potential to harm succeeding tests. - "Mangle" the printout of the current default innodb_lock_wait_timeout value --> No need to adjust the test in case the default gets changed in future. --- .../suite/innodb/r/innodb-timeout.result | 8 +- mysql-test/suite/innodb/t/innodb-timeout.test | 73 ++++++++++++++++--- 2 files changed, 68 insertions(+), 13 deletions(-) diff --git a/mysql-test/suite/innodb/r/innodb-timeout.result b/mysql-test/suite/innodb/r/innodb-timeout.result index be9a688cd72..bb71ba5cb3d 100644 --- a/mysql-test/suite/innodb/r/innodb-timeout.result +++ b/mysql-test/suite/innodb/r/innodb-timeout.result @@ -13,13 +13,14 @@ set global innodb_lock_wait_timeout=347; select @@innodb_lock_wait_timeout; @@innodb_lock_wait_timeout 42 -set innodb_lock_wait_timeout=1; +set innodb_lock_wait_timeout=10; select @@innodb_lock_wait_timeout; @@innodb_lock_wait_timeout -1 +10 select @@innodb_lock_wait_timeout; @@innodb_lock_wait_timeout 347 +SET @connection_b_id = ; create table t1(a int primary key)engine=innodb; begin; insert into t1 values(1),(2),(3); @@ -31,8 +32,9 @@ a 3 begin; insert into t1 values(4); +set innodb_lock_wait_timeout=3; select * from t1 for update; commit; ERROR HY000: Lock wait timeout exceeded; try restarting transaction drop table t1; -set global innodb_lock_wait_timeout=50; +set global innodb_lock_wait_timeout=; diff --git a/mysql-test/suite/innodb/t/innodb-timeout.test b/mysql-test/suite/innodb/t/innodb-timeout.test index f23fe3cff2d..b29aec8e83d 100644 --- a/mysql-test/suite/innodb/t/innodb-timeout.test +++ b/mysql-test/suite/innodb/t/innodb-timeout.test @@ -1,6 +1,6 @@ -- source include/have_innodb.inc -let $timeout=`select @@innodb_lock_wait_timeout`; +let $initial_timeout=`select @@innodb_lock_wait_timeout`; set global innodb_lock_wait_timeout=42; connect (a,localhost,root,,); @@ -12,19 +12,24 @@ set innodb_lock_wait_timeout=1; select @@innodb_lock_wait_timeout; connection b; +let $connection_b_id=`SELECT CONNECTION_ID()`; select @@innodb_lock_wait_timeout; set global innodb_lock_wait_timeout=347; select @@innodb_lock_wait_timeout; -set innodb_lock_wait_timeout=1; +set innodb_lock_wait_timeout=10; select @@innodb_lock_wait_timeout; connect (c,localhost,root,,); connection c; + select @@innodb_lock_wait_timeout; -connection default; + disconnect c; +--source include/wait_until_disconnected.inc connection a; +--replace_result $connection_b_id +eval SET @connection_b_id = $connection_b_id; create table t1(a int primary key)engine=innodb; begin; insert into t1 values(1),(2),(3); @@ -33,7 +38,37 @@ connection b; --send select * from t1 for update; +# Observation on information_schema.processlist (2010-12 mysql-5.5) +# ----------------------------------------------------------------- +# As soon as the server started the execution of the +# connection a: --send select ... for update +# High parallel load could delay this up to two seconds. +# and before either +# - the innodb_lock_wait_timeout was exceeded +# -> connection b reap gets ER_LOCK_WAIT_TIMEOUT +# or +# - connection a commits, the lock disappears and the statement +# of connection b finishes +# -> connection b reap gets success + result set +# we see within information_schema.processlist for connection b a row +# command state info +# Query Sending data select * from t1 for update +# The highest time value seen was @@innodb_lock_wait_timeout + 1. +# Please note that there is unfortunately nothing which says +# that we are just waiting for a lock. + connection a; +# In order to ensure that the execution of +# connection b: select * from t1 for update +# has really started and is most probably waiting for the lock now we poll on +# information_schema.processlist. +# Also our current session innodb_lock_wait_timeout of 10 seconds should big +# enough to prevent that connection b ends up with getting ER_LOCK_WAIT_TIMEOUT. +# +let $wait_timeout= 10; +let $wait_condition= SELECT COUNT(*) = 1 FROM information_schema.processlist +WHERE id = @connection_b_id AND INFO = 'select * from t1 for update'; +--source include/wait_condition.inc commit; connection b; @@ -44,21 +79,39 @@ begin; insert into t1 values(4); connection b; +set innodb_lock_wait_timeout=3; +# 3 seconds should be big enough that the wait routine of connection a will +# hit the time span where our next statement is visible within the +# information_schema.processlist. --send select * from t1 for update; connection a; -sleep 2; +# Wait till the execution of the connection b statement was started. +let $wait_timeout= 10; +let $wait_condition= SELECT COUNT(*) = 1 FROM information_schema.processlist +WHERE id = @connection_b_id AND INFO = 'select * from t1 for update'; +--source include/wait_condition.inc +# Wait till the execution of the connection b statement has ended. +let $wait_timeout= 10; +let $wait_condition= SELECT COUNT(*) = 1 FROM information_schema.processlist +WHERE id = @connection_b_id AND INFO IS NULL; +--source include/wait_condition.inc +# Give "commit" though this must be too late for the statement of connection b. commit; connection b; --error ER_LOCK_WAIT_TIMEOUT reap; -drop table t1; + +disconnect b; +--source include/wait_until_disconnected.inc + +connection a; +disconnect a; +--source include/wait_until_disconnected.inc connection default; - -disconnect a; -disconnect b; - -eval set global innodb_lock_wait_timeout=$timeout; +drop table t1; +--replace_result $initial_timeout +eval set global innodb_lock_wait_timeout=$initial_timeout;