mariadb/mysql-test/main/log_slow_debug.test

-- source include/have_debug.inc
-- source include/have_sequence.inc

SET @org_slow_query_log= @@global.slow_query_log;
SET @org_log_output= @@global.log_output;
SET @org_log_slow_admin_statements= @@global.log_slow_admin_statements;

SET @@GLOBAL.slow_query_log=OFF;
SET @@GLOBAL.log_output='TABLE';
FLUSH SLOW LOGS;
SET @@GLOBAL.slow_query_log=ON;
SET @@GLOBAL.log_slow_admin_statements=ON;
SET @saved_dbug = @@debug_dbug;
SET SESSION debug_dbug="+d,simulate_slow_query";

DELIMITER $$;
CREATE PROCEDURE show_slow_log()
BEGIN
  SELECT CONCAT('[slow] ', sql_text) AS sql_text
    FROM mysql.slow_log
     WHERE sql_text NOT LIKE '%debug_dbug%';
END
$$
DELIMITER ;$$


--echo #
--echo # Expect all admin statements in the slow log (ON,DEFAULT)
--echo #

SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=DEFAULT;
TRUNCATE TABLE mysql.slow_log;
--source include/log_slow_debug_common.inc
CALL show_slow_log();


--echo #
--echo # Expect all admin statements in the slow log (ON,admin)
--echo #

SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=admin;
TRUNCATE TABLE mysql.slow_log;
--source include/log_slow_debug_common.inc
CALL show_slow_log();


--echo #
--echo # Expect none of admin DDL statements in the slow log (ON,filesort)
--echo #

SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=filesort;
TRUNCATE TABLE mysql.slow_log;
--source include/log_slow_debug_common.inc
CALL show_slow_log();


--echo #
--echo # Expect none of admin statements in the slow log (OFF,DEFAULT)
--echo #

SET @@SESSION.log_slow_admin_statements=OFF;
SET log_slow_filter=DEFAULT;
TRUNCATE TABLE mysql.slow_log;
--source include/log_slow_debug_common.inc
CALL show_slow_log();


--echo #
--echo # Expect all admin statements in the slow log (GLOBAL OFF,LOCAL ON,DEFAULT)
--echo # In the original implementation, this combination disabled slow log for admin commands.
--echo # However, instead of this exception in GLOBAL vs LOCAL variable behaviour,
--echo # we should make max_system_variables.log_slow_admin_statements=0
--echo # prevent enabling globally suppressed logging by setting the session variable to ON.
--echo #

SET @@GLOBAL.log_slow_admin_statements=OFF;
SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=DEFAULT;
TRUNCATE TABLE mysql.slow_log;
--source include/log_slow_debug_common.inc
CALL show_slow_log();

--echo #
--echo # Start of 10.6 tests
--echo #

--echo #
--echo # MDEV-32203 Raise notes when an index cannot be used on data type
--echo # mismatch
--echo #

CREATE TABLE t1 (a VARCHAR(10), KEY(a));
insert into t1 select seq  from seq_0_to_31;

SET note_verbosity=all;
SET log_slow_verbosity=all;
SET global log_output='FILE';
set @org_slow_query_log_file=@@global.slow_query_log_file;

--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
eval set global slow_query_log_file='$MYSQLTEST_VARDIR/tmp/log_slow_debug-1.log';
FLUSH SLOW LOGS;
--disable_ps_protocol
SELECT * FROM t1 WHERE a=10;
EXPLAIN SELECT * FROM t1 WHERE a=10;
--enable_ps_protocol

--let SEARCH_FILE = `SELECT @@slow_query_log_file`
--let SEARCH_PATTERN=# Warnings
--source include/search_pattern_in_file.inc
--let SEARCH_PATTERN= # Note.*Cannot use key.*varchar.*10.*int
--source include/search_pattern_in_file.inc

--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
eval set global slow_query_log_file='$MYSQLTEST_VARDIR/tmp/log_slow_debug-2.log';
SET note_verbosity="explain";
FLUSH SLOW LOGS;
EXPLAIN SELECT * FROM t1 WHERE a=10;

--let SEARCH_FILE = `SELECT @@slow_query_log_file`
--let SEARCH_PATTERN=# Warnings
--source include/search_pattern_in_file.inc
--let SEARCH_PATTERN= # Note.*Cannot use key.*varchar.*10.*int
--source include/search_pattern_in_file.inc

--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
eval set global slow_query_log_file='$MYSQLTEST_VARDIR/tmp/log_slow_debug-3.log';
SET log_slow_verbosity=replace(@@log_slow_verbosity, "warnings", "");
SET log_slow_verbosity=replace(@@log_slow_verbosity, "full", "");
SET note_verbosity=all;
FLUSH SLOW LOGS;
SELECT * FROM t1 WHERE a=10;
EXPLAIN SELECT * FROM t1 WHERE a=10;

--let SEARCH_FILE = `SELECT @@slow_query_log_file`
--let SEARCH_PATTERN=# Warnings
--source include/search_pattern_in_file.inc
--let SEARCH_PATTERN= # Note.*Cannot use key.*varchar.*10.*int
--source include/search_pattern_in_file.inc

set @@global.slow_query_log_file= @org_slow_query_log_file;

--remove_file $MYSQLTEST_VARDIR/tmp/log_slow_debug-1.log
--remove_file $MYSQLTEST_VARDIR/tmp/log_slow_debug-2.log
--remove_file $MYSQLTEST_VARDIR/tmp/log_slow_debug-3.log

DROP TABLE t1;

--echo #
--echo # MDEV-30820: slow log Rows_examined out of range
--echo #

CREATE TABLE `tab_MDEV_30820` (
`ID` int(11) NOT NULL AUTO_INCREMENT,
`A` int(11),
PRIMARY KEY(ID)
);

insert into tab_MDEV_30820 values (null, 0),(null, 0);

SET @old_slow_query_log= @@global.slow_query_log;
SET @old_log_output= @@global.log_output;
SET @old_long_query_time= @@long_query_time;
SET @old_dbug= @@GLOBAL.debug_dbug;
SET GLOBAL log_output= "TABLE";

SET GLOBAL slow_query_log= ON;
SET SESSION long_query_time= 0;

SET debug_dbug="+d,debug_huge_number_of_examined_rows";
--disable_ps_protocol
--disable_view_protocol
SELECT * FROM tab_MDEV_30820 ORDER BY 1;
--enable_view_protocol
--enable_ps_protocol
SET debug_dbug=@old_dbug;

## Reset to initial values
SET @@long_query_time= @old_long_query_time;
SET @@global.log_output= @old_log_output;
SET @@global.slow_query_log= @old_slow_query_log;

SELECT rows_examined, sql_text from mysql.slow_log where sql_text like "SELECT%FROM tab_MDEV_30820%";

drop table tab_MDEV_30820;

--echo #
--echo # End of 10.4 test
--echo #

--echo #
--echo # Clean up
--echo #

SET SESSION debug_dbug=@saved_dbug;
TRUNCATE mysql.slow_log;
SET @@global.slow_query_log= @org_slow_query_log;
SET @@global.log_output= @org_log_output;
SET @@global.log_slow_admin_statements= @org_log_slow_admin_statements;
DROP PROCEDURE show_slow_log;