The first test case is for 4 options each set via SET STATEMENT var FOR query. Every part of the test fails -- whatever is expected does not happen.
To make sure that the test itself is valid, the second test case is provided. It does exactly the same, but via old-fashioned SET var; query; unset var. It works as expected.
The second connection in the test is used to avoid side effects of the other bugs.
##################################
# Test case 1 (SET STATEMENT)
--let $slowlog = `select @@slow_query_log_file`
set @log_output.saved = @@global.log_output;
set @slow_query_log.saved = @@global.slow_query_log;
set global log_output = 'FILE', global slow_query_log = 1;
set min_examined_row_limit = 0, long_query_time = 10;
--connect (con1,localhost,root,,)
set statement LONG_QUERY_TIME = 0.01 for select sleep(0.11);
--echo #--------------------------------------------------------------------
--echo # The last set statement is expected to be in the log
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
set long_query_time = 0.01;
set statement LOG_SLOW_FILTER = 'full_scan' for select sleep(0.14);
--echo #--------------------------------------------------------------------
--echo # The last set statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
set statement LOG_SLOW_VERBOSITY = 'innodb' for select host, sleep(0.15) from mysql.user where user = 'root';
--echo #--------------------------------------------------------------------
--echo # The last set statement should have something about InnoDB stats
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
set statement LOG_SLOW_RATE_LIMIT = 4 for select sleep(0.16);
--echo #--------------------------------------------------------------------
--echo # The last set statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
--disconnect con1
--connection default
set global log_output = @log_output.saved;
set global slow_query_log = @slow_query_log.saved;
set min_examined_row_limit = 0;
##################################
# Test case 2 (SET)
--let $slowlog = `select @@slow_query_log_file`
set @log_output.saved = @@global.log_output;
set @slow_query_log.saved = @@global.slow_query_log;
set global log_output = 'FILE', global slow_query_log = 1;
set min_examined_row_limit = 0, long_query_time = 10;
--connect (con1,localhost,root,,)
set LONG_QUERY_TIME = 0.01;
select sleep(0.11);
set LONG_QUERY_TIME = DEFAULT;
--echo #--------------------------------------------------------------------
--echo # The last select statement is expected to be in the log
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
set long_query_time = 0.01;
set LOG_SLOW_FILTER = 'full_scan';
select sleep(0.14);
set LOG_SLOW_FILTER = DEFAULT;
--echo #--------------------------------------------------------------------
--echo # The last select statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
set LOG_SLOW_VERBOSITY = 'innodb';
select host, sleep(0.15) from mysql.user where user = 'root';
set LOG_SLOW_VERBOSITY = DEFAULT;
--echo #--------------------------------------------------------------------
--echo # The last select statement should have something about InnoDB stats
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
set LOG_SLOW_RATE_LIMIT = 4;
select sleep(0.16);
set LOG_SLOW_RATE_LIMIT = DEFAULT;
--echo #--------------------------------------------------------------------
--echo # The last select statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #--------------------------------------------------------------------
--disconnect con1
--connection default
set global log_output = @log_output.saved;
set global slow_query_log = @slow_query_log.saved;
set min_examined_row_limit = 0;
################################################
Final log for the 1st test case:
/data/repo/bzr/percona-5.6/sql/mysqld, Version: 5.6.21-69.0-debug-log (Source distribution). started with:
Tcp port: 13001 Unix socket: /data/repo/bzr/percona-5.6/mysql-test/var/tmp/mysqld.1.sock
Time Id Command Argument
# Time: 141102 23:56:11
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.140614 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0
# Bytes_sent: 66
use test;
SET timestamp=1414961771;
set statement LOG_SLOW_FILTER = 'full_scan' for select sleep(0.14);
# Time: 141102 23:56:12
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.602489 Lock_time: 0.000316 Rows_sent: 4 Rows_examined: 4 Rows_affected: 0
# Bytes_sent: 165
SET timestamp=1414961772;
set statement LOG_SLOW_VERBOSITY = 'innodb' for select host, sleep(0.15) from mysql.user where user = 'root';
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.161236 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0
# Bytes_sent: 66
SET timestamp=1414961772;
set statement LOG_SLOW_RATE_LIMIT = 4 for select sleep(0.16);
################################################
Final log for the 2nd test case:
/data/repo/bzr/percona-5.6/sql/mysqld, Version: 5.6.21-69.0-debug-log (Source distribution). started with:
Tcp port: 13001 Unix socket: /data/repo/bzr/percona-5.6/mysql-test/var/tmp/mysqld.1.sock
Time Id Command Argument
# Time: 141102 23:48:42
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.113348 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0
# Bytes_sent: 66
use test;
SET timestamp=1414961322;
select sleep(0.11);
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.601798 Lock_time: 0.000317 Rows_sent: 4 Rows_examined: 4 Rows_affected: 0
# Bytes_sent: 165
# No InnoDB statistics available for this query
SET timestamp=1414961322;
select host, sleep(0.15) from mysql.user where user = 'root';
The first test case is for 4 options each set via SET STATEMENT var FOR query. Every part of the test fails -- whatever is expected does not happen.
To make sure that the test itself is valid, the second test case is provided. It does exactly the same, but via old-fashioned SET var; query; unset var. It works as expected.
The second connection in the test is used to avoid side effects of the other bugs.
See also https:/ /bugs.launchpad .net/percona- server/ +bug/1388526 for min_examined_ row_limit.
####### ####### ####### ####### ######
# Test case 1 (SET STATEMENT)
--let $slowlog = `select @@slow_ query_log_ file`
set @log_output.saved = @@global. log_output; log.saved = @@global. slow_query_ log;
set @slow_query_
set global log_output = 'FILE', global slow_query_log = 1; row_limit = 0, long_query_time = 10;
set min_examined_
--connect (con1,localhost ,root,, )
set statement LONG_QUERY_TIME = 0.01 for select sleep(0.11); ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
--echo #------
--echo # The last set statement is expected to be in the log
--echo #------
cat_file $slowlog;
--echo #------
set long_query_time = 0.01;
set statement LOG_SLOW_FILTER = 'full_scan' for select sleep(0.14); ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
--echo #------
--echo # The last set statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #------
set statement LOG_SLOW_VERBOSITY = 'innodb' for select host, sleep(0.15) from mysql.user where user = 'root'; ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
--echo #------
--echo # The last set statement should have something about InnoDB stats
--echo #------
cat_file $slowlog;
--echo #------
set statement LOG_SLOW_RATE_LIMIT = 4 for select sleep(0.16); ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
--echo #------
--echo # The last set statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #------
--disconnect con1
--connection default log.saved; row_limit = 0;
set global log_output = @log_output.saved;
set global slow_query_log = @slow_query_
set min_examined_
####### ####### ####### ####### ######
# Test case 2 (SET)
--let $slowlog = `select @@slow_ query_log_ file`
set @log_output.saved = @@global. log_output; log.saved = @@global. slow_query_ log;
set @slow_query_
set global log_output = 'FILE', global slow_query_log = 1; row_limit = 0, long_query_time = 10;
set min_examined_
--connect (con1,localhost ,root,, )
set LONG_QUERY_TIME = 0.01; ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
select sleep(0.11);
set LONG_QUERY_TIME = DEFAULT;
--echo #------
--echo # The last select statement is expected to be in the log
--echo #------
cat_file $slowlog;
--echo #------
set long_query_time = 0.01;
set LOG_SLOW_FILTER = 'full_scan'; ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
select sleep(0.14);
set LOG_SLOW_FILTER = DEFAULT;
--echo #------
--echo # The last select statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #------
set LOG_SLOW_VERBOSITY = 'innodb'; ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
select host, sleep(0.15) from mysql.user where user = 'root';
set LOG_SLOW_VERBOSITY = DEFAULT;
--echo #------
--echo # The last select statement should have something about InnoDB stats
--echo #------
cat_file $slowlog;
--echo #------
set LOG_SLOW_RATE_LIMIT = 4; ------- ------- ------- ------- ------- ------- ------- ------- ------ ------- ------- ------- ------- ------- ------- ------- ------- ------
select sleep(0.16);
set LOG_SLOW_RATE_LIMIT = DEFAULT;
--echo #------
--echo # The last select statement is NOT expected to be in the log
--echo #------
cat_file $slowlog;
--echo #------
--disconnect con1
--connection default log.saved; row_limit = 0;
set global log_output = @log_output.saved;
set global slow_query_log = @slow_query_
set min_examined_
####### ####### ####### ####### ####### ####### ######
Final log for the 1st test case:
/data/repo/ bzr/percona- 5.6/sql/ mysqld, Version: 5.6.21- 69.0-debug- log (Source distribution). started with: bzr/percona- 5.6/mysql- test/var/ tmp/mysqld. 1.sock 1414961771; 1414961772; 1414961772;
Tcp port: 13001 Unix socket: /data/repo/
Time Id Command Argument
# Time: 141102 23:56:11
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.140614 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0
# Bytes_sent: 66
use test;
SET timestamp=
set statement LOG_SLOW_FILTER = 'full_scan' for select sleep(0.14);
# Time: 141102 23:56:12
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.602489 Lock_time: 0.000316 Rows_sent: 4 Rows_examined: 4 Rows_affected: 0
# Bytes_sent: 165
SET timestamp=
set statement LOG_SLOW_VERBOSITY = 'innodb' for select host, sleep(0.15) from mysql.user where user = 'root';
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.161236 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0
# Bytes_sent: 66
SET timestamp=
set statement LOG_SLOW_RATE_LIMIT = 4 for select sleep(0.16);
####### ####### ####### ####### ####### ####### ######
Final log for the 2nd test case:
/data/repo/ bzr/percona- 5.6/sql/ mysqld, Version: 5.6.21- 69.0-debug- log (Source distribution). started with: bzr/percona- 5.6/mysql- test/var/ tmp/mysqld. 1.sock 1414961322; 1414961322;
Tcp port: 13001 Unix socket: /data/repo/
Time Id Command Argument
# Time: 141102 23:48:42
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.113348 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 Rows_affected: 0
# Bytes_sent: 66
use test;
SET timestamp=
select sleep(0.11);
# User@Host: root[root] @ localhost [] Id: 3
# Schema: test Last_errno: 0 Killed: 0
# Query_time: 0.601798 Lock_time: 0.000317 Rows_sent: 4 Rows_examined: 4 Rows_affected: 0
# Bytes_sent: 165
# No InnoDB statistics available for this query
SET timestamp=
select host, sleep(0.15) from mysql.user where user = 'root';