mirror of
https://github.com/MariaDB/server.git
synced 2025-01-17 20:42:30 +01:00
Fix for
Bug#36345 Test 'func_misc' fails on RHAS3 x86_64 and a second similar problem within this test found during experimenting.
This commit is contained in:
First_name Last_name mleich@mysql.com
parent
8c490b78df
commit
72b623eef0
2 changed files with 343 additions and 49 deletions
|
|
@ -104,41 +104,76 @@ t1 CREATE TABLE `t1` (
|
|||
`length(uuid())` int(10) NOT NULL DEFAULT '0'
|
||||
) ENGINE=MyISAM DEFAULT CHARSET=latin1
|
||||
drop table t1;
|
||||
create table t1 (a timestamp default '2005-05-05 01:01:01',
|
||||
create table t1 (id int,
|
||||
a timestamp default '2005-05-05 01:01:01',
|
||||
b timestamp default '2005-05-05 01:01:01');
|
||||
insert into t1 set a = now();
|
||||
insert into t1 set id = 1,a = now();
|
||||
select sleep(3);
|
||||
sleep(3)
|
||||
0
|
||||
update t1 set b = now();
|
||||
select timediff(b, a) >= '00:00:03' from t1;
|
||||
timediff(b, a) >= '00:00:03'
|
||||
update t1 set b = now() where id = 1;
|
||||
insert into t1 set id = 2,a = now();
|
||||
select sleep(3);
|
||||
sleep(3)
|
||||
0
|
||||
update t1 set b = now() where id = 2;
|
||||
select count(*) >= 1 from t1
|
||||
where timediff(b, a) between '00:00:03' and '00:00:07';
|
||||
count(*) >= 1
|
||||
1
|
||||
drop table t1;
|
||||
set global query_cache_size=1355776;
|
||||
create table t1 (a int);
|
||||
insert into t1 values (1),(1),(1);
|
||||
create table t2 (a datetime default null, b datetime default null);
|
||||
insert into t2 set a = now();
|
||||
select a from t1 where sleep(1);
|
||||
a
|
||||
update t2 set b = now() where b is null;
|
||||
insert into t2 set a = now();
|
||||
select a from t1 where sleep(a);
|
||||
a
|
||||
update t2 set b = now() where b is null;
|
||||
insert into t2 set a = now();
|
||||
select a from t1 where sleep(1);
|
||||
a
|
||||
update t2 set b = now() where b is null;
|
||||
select timediff(b, a) >= '00:00:03' from t2;
|
||||
timediff(b, a) >= '00:00:03'
|
||||
SET @@global.query_cache_size = 1024 * 64;
|
||||
SELECT 1 as some_value, sleep(1);
|
||||
some_value sleep(1)
|
||||
1 0
|
||||
SELECT <Qcache_queries_in_cache_before> = <Qcache_queries_in_cache_before>
|
||||
AS "Was the query not cached (= expectation)?";
|
||||
Was the query not cached (= expectation)?
|
||||
1
|
||||
DROP TEMPORARY TABLE IF EXISTS proclist_history;
|
||||
DROP TABLE IF EXISTS t1;
|
||||
CREATE TEMPORARY TABLE proclist_history AS
|
||||
SELECT 'Bug 1' AS test, 0 AS attempt, NOW() AS observation_time, state, time
|
||||
FROM information_schema.processlist WHERE 1 = 0;
|
||||
CREATE TABLE t1 (f1 BIGINT);
|
||||
INSERT INTO t1 VALUES (1);
|
||||
INSERT INTO t1 VALUES (1);
|
||||
INSERT INTO t1 VALUES (1);
|
||||
INSERT INTO t1 VALUES (1);
|
||||
SET @sleep_time_per_result_row = 1;
|
||||
----- establish connection con1 (user = root) -----
|
||||
SET @sleep_time_per_result_row = 1;
|
||||
Qcache_queries_in_cache: 0
|
||||
# Send query with send, pull server responses later
|
||||
SELECT sleep(@sleep_time_per_result_row) FROM t1;
|
||||
----- switch to connection default (user = root) -----
|
||||
----- switch to connection con1 (user = root) -----
|
||||
# Pull server responses of last query
|
||||
sleep(@sleep_time_per_result_row)
|
||||
0
|
||||
0
|
||||
0
|
||||
0
|
||||
----- switch to connection con1 (user = root) -----
|
||||
# Send query with send, pull server responses later
|
||||
SELECT sleep(@sleep_time_per_result_row) FROM t1;
|
||||
----- switch to connection default (user = root) -----
|
||||
SELECT COUNT(*) FROM information_schema.processlist
|
||||
WHERE info = 'SELECT sleep(@sleep_time_per_result_row) FROM t1'
|
||||
AND state = 'User sleep';
|
||||
COUNT(*)
|
||||
1
|
||||
1
|
||||
drop table t2;
|
||||
drop table t1;
|
||||
set global query_cache_size=default;
|
||||
----- switch to connection con1 (user = root) -----
|
||||
# Pull server responses of last query
|
||||
sleep(@sleep_time_per_result_row)
|
||||
0
|
||||
0
|
||||
0
|
||||
0
|
||||
----- switch to connection default and close connection con1 -----
|
||||
SET @@global.query_cache_size = default;
|
||||
DROP TABLE t1;
|
||||
DROP TEMPORARY TABLE proclist_history;
|
||||
create table t1 select INET_ATON('255.255.0.1') as `a`;
|
||||
show create table t1;
|
||||
Table Create Table
|
||||
|
|
|
|||
|
|
@ -105,34 +105,293 @@ drop table t1;
|
|||
#
|
||||
# Bug #6760: Add SLEEP() function
|
||||
#
|
||||
create table t1 (a timestamp default '2005-05-05 01:01:01',
|
||||
# Note (mleich):
|
||||
# --------------
|
||||
# The experiments around
|
||||
# Bug#36345 Test 'func_misc' fails on RHAS3 x86_64
|
||||
# showed that the original test for Bug#6760 produced false alarms in case
|
||||
# of parallel system time decreases. It was therefore modified.
|
||||
# Solution:
|
||||
# We run the test two times and assume a pass if at least one attempt
|
||||
# is successful. The disadvantage is that a parallel "unnatural" increase of
|
||||
# system time (set time via ntpd etc.) is able to hide a wrong working SLEEP
|
||||
# function. This is no problem because
|
||||
# - such changes of the system are rare
|
||||
# - there is an extreme high probability that either the following test
|
||||
# or the frequent runs of the current test on the current testing box or
|
||||
# other boxes catch a wrong working SLEEP function.
|
||||
create table t1 (id int,
|
||||
a timestamp default '2005-05-05 01:01:01',
|
||||
b timestamp default '2005-05-05 01:01:01');
|
||||
insert into t1 set a = now();
|
||||
insert into t1 set id = 1,a = now();
|
||||
select sleep(3);
|
||||
update t1 set b = now();
|
||||
select timediff(b, a) >= '00:00:03' from t1;
|
||||
update t1 set b = now() where id = 1;
|
||||
insert into t1 set id = 2,a = now();
|
||||
select sleep(3);
|
||||
update t1 set b = now() where id = 2;
|
||||
# Check that the timediff caused by the length of the sleep is not plain wrong.
|
||||
# We can have delays in statement processing of 1 - 2 seconds on
|
||||
# an overloaded testing box.
|
||||
# Minimum (= ideal) real timediff = '00:00:03'
|
||||
# Maximum acceptable real timediff = '00:00:07'
|
||||
select count(*) >= 1 from t1
|
||||
where timediff(b, a) between '00:00:03' and '00:00:07';
|
||||
drop table t1;
|
||||
|
||||
#
|
||||
################################################################################
|
||||
# Bug #12689: SLEEP() gets incorrectly cached/optimized-away
|
||||
#
|
||||
set global query_cache_size=1355776;
|
||||
create table t1 (a int);
|
||||
insert into t1 values (1),(1),(1);
|
||||
create table t2 (a datetime default null, b datetime default null);
|
||||
insert into t2 set a = now();
|
||||
select a from t1 where sleep(1);
|
||||
update t2 set b = now() where b is null;
|
||||
insert into t2 set a = now();
|
||||
select a from t1 where sleep(a);
|
||||
update t2 set b = now() where b is null;
|
||||
insert into t2 set a = now();
|
||||
select a from t1 where sleep(1);
|
||||
update t2 set b = now() where b is null;
|
||||
select timediff(b, a) >= '00:00:03' from t2;
|
||||
drop table t2;
|
||||
drop table t1;
|
||||
set global query_cache_size=default;
|
||||
# Description from bug report (slightly modified)
|
||||
# ===============================================
|
||||
# Bug 1 (happened all time):
|
||||
# SELECT * FROM t1 WHERE SLEEP(1) will only result in a sleep of 1
|
||||
# second, regardless of the number of rows in t1.
|
||||
# Bug 2 (happened all time):
|
||||
# Such a query will also get cached by the query cache, but should not.
|
||||
#
|
||||
# Notes (mleich, May 2008)
|
||||
# ========================
|
||||
# 1. The testcase for this bug had to be reimplemented because of
|
||||
# Bug#36345 Test 'func_misc' fails on RHAS3 x86_64
|
||||
# - Bad effect: We did not reach the expected time differences.
|
||||
# - Experiments showed that for example a parallel change of the system
|
||||
# time (decrease of time value) like via ntpd provokes this effect.
|
||||
#
|
||||
# It is a clear error within the setup of the testing environment if
|
||||
# tests relying on derivates of the system time can meet parallel
|
||||
# manipulations of this time. Covering these weaknesses by workarounds
|
||||
# within the tests is often not perfect doable at all and costs
|
||||
# significant development and/or runtime per test.
|
||||
#
|
||||
# Results of experiments with/without manipulation of system time:
|
||||
# ----------------------------------------------------------------
|
||||
# Definition: Predicted_cumulative_sleep_time =
|
||||
# #_of_result_rows * sleep_time_per_result_row
|
||||
# processlist.time refers to the session in state 'User sleep'
|
||||
#
|
||||
# 1. Total (real sleep time) ~= predicted_cumulative_sleep_time !!
|
||||
# 2. processlist.time behaves "synchronous" to system time and NOW() and
|
||||
# shows also the "jumps" caused by system time manipulations
|
||||
# 3. processlist.time is unsigned, the next value below 0 is ~ 4G
|
||||
# 4. Current processlist.time ~= current real sleep time
|
||||
# if the system time was not manipulated
|
||||
#
|
||||
# 2. How to reveal the absence of Bug 1:
|
||||
#
|
||||
# The state of a session within the PROCESSLIST changes to 'User sleep'
|
||||
# if the sessions runs a statement containing the sleep function and the
|
||||
# processing of the statement is just within the phase where the sleep
|
||||
# is done.
|
||||
#
|
||||
# As soon as the "Real" time where the session is in state 'User sleep'
|
||||
# exceeds the sleep_time_per_result_row we can be sure that the execution
|
||||
# of the query slept more time than needed for just one row.
|
||||
#
|
||||
# "Real" time in state 'User sleep' > sleep_time_per_result_row
|
||||
#
|
||||
# Estimation 1:
|
||||
# -------------
|
||||
# n = how often we observed the session is in state 'User sleep'
|
||||
#
|
||||
# "Real" time in state 'User sleep'
|
||||
# = (n - 1) * sleep_time_in_loop
|
||||
# + time needed for the execution of the statements within the loop
|
||||
# (includes the time waiting for getting resources like CPU etc.
|
||||
# which si significant in case of high load on testing box)
|
||||
#
|
||||
# (n - 1) * sleep_time_in_loop >= sleep_time_per_result_row
|
||||
#
|
||||
# n >= sleep_time_per_result_row / sleep_time_in_loop + 1
|
||||
#
|
||||
# Simplification taking truncation of values etc. into account:
|
||||
# n >= sleep_time_per_result_row / sleep_time_in_loop + 2
|
||||
#
|
||||
# We cannot have met Bug 1 if
|
||||
# n >= sleep_time_per_result_row / sleep_time_in_loop + 2
|
||||
# is fulfilled.
|
||||
# But there is a significant risk that a run on an overloaded box
|
||||
# does not reach the estimated limit.
|
||||
#
|
||||
# Estimation 2:
|
||||
# -------------
|
||||
# processlist.time should show how long a session is within the current
|
||||
# state. I verified by experimenting that this value is not reset per
|
||||
# row of the the result set.
|
||||
#
|
||||
# "Real" time in state 'User sleep'
|
||||
# >= highest observed value of processlist.time
|
||||
#
|
||||
# We cannot have met Bug 1 if
|
||||
# highest observed value of processlist.time > sleep_time_per_result_row
|
||||
# is fulfilled.
|
||||
# Unfortunately processlist.time is no more reliable in case of parallel
|
||||
# changes of the system time.
|
||||
#
|
||||
# Final solution:
|
||||
# ---------------
|
||||
# Run a subtest with "judging" based on estimation 1. If the limit is not
|
||||
# reached, assume that we suffered from high load and try estimation 2.
|
||||
# If estimation 2 gets cheated by parallel increase of system time
|
||||
# assume that later runs on the same box or other boxes will show if
|
||||
# Bug#12689 occured again.
|
||||
#
|
||||
# 3. How to reveal the absence of Bug 2:
|
||||
# - By checking the behaviour during second execution:
|
||||
# We run the same statement again and meet the session at least once in
|
||||
# state 'User sleep'.
|
||||
# - By checking secondary information (query cache statistics)
|
||||
# The first execution of the statment must not cause that
|
||||
# Qcache_queries_in_cache is incremented.
|
||||
#
|
||||
# 4. We do not run
|
||||
# --source include/have_query_cache.inc
|
||||
# at the beginning of this script because we want that this script is not
|
||||
# skipped if the query cache is disabled. This means the detection of wrongly
|
||||
# cached queries is in such cases without real effect.
|
||||
#
|
||||
# 5. Thanks to Davi for excellent hints and ideas.
|
||||
#
|
||||
################################################################################
|
||||
|
||||
# 1. For Bug 2: Qcache_queries_in_cache must be not incremented if a query with
|
||||
# sleep was first time executed.
|
||||
SET @@global.query_cache_size = 1024 * 64;
|
||||
let $Qcache_queries_in_cache_before =
|
||||
query_get_value(SHOW STATUS LIKE 'Qcache_queries_in_cache', Value, 1);
|
||||
SELECT 1 as some_value, sleep(1);
|
||||
let $Qcache_queries_in_cache_after =
|
||||
query_get_value(SHOW STATUS LIKE 'Qcache_queries_in_cache', Value, 1);
|
||||
# Show that the query with sleep was not cached via query cache statistics.
|
||||
--replace_result $Qcache_queries_in_cache_before <Qcache_queries_in_cache_before> $Qcache_queries_in_cache_after <Qcache_queries_in_cache_after>
|
||||
eval SELECT $Qcache_queries_in_cache_before = $Qcache_queries_in_cache_after
|
||||
AS "Was the query not cached (= expectation)?";
|
||||
#
|
||||
# 2. For Bug 1: Estimation 1
|
||||
# Real sleep time must exceed the sleep time for just one row.
|
||||
#
|
||||
let $sleep_time_per_result_row = 1;
|
||||
let $row_count = 4;
|
||||
|
||||
--disable_warnings
|
||||
DROP TEMPORARY TABLE IF EXISTS proclist_history;
|
||||
DROP TABLE IF EXISTS t1;
|
||||
--enable_warnings
|
||||
CREATE TEMPORARY TABLE proclist_history AS
|
||||
SELECT 'Bug 1' AS test, 0 AS attempt, NOW() AS observation_time, state, time
|
||||
FROM information_schema.processlist WHERE 1 = 0;
|
||||
CREATE TABLE t1 (f1 BIGINT);
|
||||
let $num = $row_count;
|
||||
while ($num)
|
||||
{
|
||||
INSERT INTO t1 VALUES (1);
|
||||
dec $num;
|
||||
}
|
||||
|
||||
eval SET @sleep_time_per_result_row = $sleep_time_per_result_row;
|
||||
let $sleep_command = SELECT sleep(@sleep_time_per_result_row) FROM t1;
|
||||
|
||||
# Set wait_timeout to a useful small value.
|
||||
let $wait_timeout= `SELECT $row_count * $sleep_time_per_result_row + 5`;
|
||||
let $wait_condition =
|
||||
SELECT COUNT(*) >= @sleep_time_per_result_row / 0.1 + 2
|
||||
FROM proclist_history WHERE test = 'Bug 1';
|
||||
|
||||
--echo ----- establish connection con1 (user = root) -----
|
||||
connect (con1,localhost,root,,);
|
||||
eval SET @sleep_time_per_result_row = $sleep_time_per_result_row;
|
||||
let $Qcache_queries_in_cache_before =
|
||||
query_get_value(SHOW STATUS LIKE 'Qcache_queries_in_cache', Value, 1);
|
||||
--echo Qcache_queries_in_cache: $Qcache_queries_in_cache_before
|
||||
--echo # Send query with send, pull server responses later
|
||||
send;
|
||||
eval $sleep_command;
|
||||
#
|
||||
--echo ----- switch to connection default (user = root) -----
|
||||
connection default;
|
||||
#
|
||||
--disable_query_log
|
||||
let $wait_counter= `SELECT $wait_timeout * 10`;
|
||||
let $wait_condition_reps= 0;
|
||||
while ($wait_counter)
|
||||
{
|
||||
let $success= `$wait_condition`;
|
||||
inc $wait_condition_reps;
|
||||
eval
|
||||
INSERT INTO proclist_history
|
||||
( test, attempt, observation_time, state, time)
|
||||
SELECT 'Bug 1', $wait_condition_reps, NOW(), state, time
|
||||
FROM information_schema.processlist
|
||||
WHERE info = '$sleep_command';
|
||||
if ($success)
|
||||
{
|
||||
let $wait_counter= 0;
|
||||
}
|
||||
if (!$success)
|
||||
{
|
||||
real_sleep 0.1;
|
||||
dec $wait_counter;
|
||||
}
|
||||
}
|
||||
--enable_query_log
|
||||
if (!$success)
|
||||
{
|
||||
# Estimation 1 had no success - We are most probably on a testing box
|
||||
# running under high load.
|
||||
# Try Estimation 2:
|
||||
let $success = `SELECT MAX(time) > @sleep_time_per_result_row
|
||||
FROM proclist_history WHERE test = 'Bug 1'`;
|
||||
}
|
||||
if (!$success)
|
||||
{
|
||||
--echo # ------------------------------------------------------------
|
||||
--echo # The check for
|
||||
--echo # Bug#12689: SLEEP() gets incorrectly cached/optimized-away
|
||||
--echo # failed. None of both estimations are fulfilled.
|
||||
--echo #
|
||||
--echo # Dumping debug information
|
||||
--echo #
|
||||
--echo # Estimation 1:
|
||||
eval $wait_condition;
|
||||
--echo # ------------------------------------------------------------
|
||||
--echo # Estimation 2:
|
||||
SELECT MAX(time) > @sleep_time_per_result_row
|
||||
FROM proclist_history WHERE test = 'Bug 1';
|
||||
--echo # ------------------------------------------------------------
|
||||
SELECT attempt, observation_time, state, time FROM proclist_history
|
||||
WHERE test = 'Bug 1' ORDER BY attempt;
|
||||
--echo # ------------------------------------------------------------
|
||||
}
|
||||
--echo ----- switch to connection con1 (user = root) -----
|
||||
connection con1;
|
||||
--echo # Pull server responses of last query
|
||||
reap;
|
||||
#
|
||||
# 3. For Bug 2: A second execution of the same statement must again show
|
||||
# the session in state 'User sleep'.
|
||||
--echo ----- switch to connection con1 (user = root) -----
|
||||
connection con1;
|
||||
--echo # Send query with send, pull server responses later
|
||||
send;
|
||||
eval $sleep_command;
|
||||
#
|
||||
--echo ----- switch to connection default (user = root) -----
|
||||
connection default;
|
||||
let $wait_condition = SELECT COUNT(*) FROM information_schema.processlist
|
||||
WHERE info = '$sleep_command'
|
||||
AND state = 'User sleep';
|
||||
--source include/wait_condition.inc
|
||||
# Simply show that we reached the expected state.
|
||||
eval $wait_condition;
|
||||
--echo ----- switch to connection con1 (user = root) -----
|
||||
connection con1;
|
||||
--echo # Pull server responses of last query
|
||||
reap;
|
||||
--echo ----- switch to connection default and close connection con1 -----
|
||||
connection default;
|
||||
disconnect con1;
|
||||
SET @@global.query_cache_size = default;
|
||||
DROP TABLE t1;
|
||||
DROP TEMPORARY TABLE proclist_history;
|
||||
|
||||
#
|
||||
# Bug #21466: INET_ATON() returns signed, not unsigned
|
||||
|
|
|
|||
Loading…
Reference in a new issue