mariadb/mysql-test/main/log_slow_debug.result
2023-12-17 11:20:43 +01:00

314 lines
9.7 KiB
Text

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";
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
$$
#
# Expect all admin statements in the slow log (ON,DEFAULT)
#
SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=DEFAULT;
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE INDEX t1a ON t1 (a);
DROP INDEX t1a ON t1;
DROP TABLE t1;
CREATE TABLE t2 (a INT);
ALTER TABLE t2 RENAME t2;
RENAME TABLE t2 TO t3;
DROP TABLE t3;
CREATE TABLE t4 (a INT);
PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP TABLE t4;
CREATE SEQUENCE s4;
ALTER SEQUENCE s4 MAXVALUE 100;
PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP SEQUENCE s4;
CALL show_slow_log();
sql_text
[slow] TRUNCATE TABLE mysql.slow_log
[slow] CREATE TABLE t1 (a INT)
[slow] CREATE INDEX t1a ON t1 (a)
[slow] DROP INDEX t1a ON t1
[slow] DROP TABLE t1
[slow] CREATE TABLE t2 (a INT)
[slow] ALTER TABLE t2 RENAME t2
[slow] RENAME TABLE t2 TO t3
[slow] DROP TABLE t3
[slow] CREATE TABLE t4 (a INT)
[slow] PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1'
[slow] ALTER TABLE t4 MODIFY a INT DEFAULT 1
[slow] DEALLOCATE PREPARE stmt
[slow] DROP TABLE t4
[slow] CREATE SEQUENCE s4
[slow] ALTER SEQUENCE s4 MAXVALUE 100
[slow] PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101'
[slow] ALTER SEQUENCE s4 MAXVALUE=101
[slow] DEALLOCATE PREPARE stmt
[slow] DROP SEQUENCE s4
#
# Expect all admin statements in the slow log (ON,admin)
#
SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=admin;
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE INDEX t1a ON t1 (a);
DROP INDEX t1a ON t1;
DROP TABLE t1;
CREATE TABLE t2 (a INT);
ALTER TABLE t2 RENAME t2;
RENAME TABLE t2 TO t3;
DROP TABLE t3;
CREATE TABLE t4 (a INT);
PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP TABLE t4;
CREATE SEQUENCE s4;
ALTER SEQUENCE s4 MAXVALUE 100;
PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP SEQUENCE s4;
CALL show_slow_log();
sql_text
[slow] CREATE INDEX t1a ON t1 (a)
[slow] DROP INDEX t1a ON t1
[slow] ALTER TABLE t2 RENAME t2
[slow] RENAME TABLE t2 TO t3
[slow] ALTER TABLE t4 MODIFY a INT DEFAULT 1
[slow] ALTER SEQUENCE s4 MAXVALUE 100
[slow] ALTER SEQUENCE s4 MAXVALUE=101
#
# Expect none of admin DDL statements in the slow log (ON,filesort)
#
SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=filesort;
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE INDEX t1a ON t1 (a);
DROP INDEX t1a ON t1;
DROP TABLE t1;
CREATE TABLE t2 (a INT);
ALTER TABLE t2 RENAME t2;
RENAME TABLE t2 TO t3;
DROP TABLE t3;
CREATE TABLE t4 (a INT);
PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP TABLE t4;
CREATE SEQUENCE s4;
ALTER SEQUENCE s4 MAXVALUE 100;
PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP SEQUENCE s4;
CALL show_slow_log();
sql_text
#
# Expect none of admin statements in the slow log (OFF,DEFAULT)
#
SET @@SESSION.log_slow_admin_statements=OFF;
SET log_slow_filter=DEFAULT;
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE INDEX t1a ON t1 (a);
DROP INDEX t1a ON t1;
DROP TABLE t1;
CREATE TABLE t2 (a INT);
ALTER TABLE t2 RENAME t2;
RENAME TABLE t2 TO t3;
DROP TABLE t3;
CREATE TABLE t4 (a INT);
PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP TABLE t4;
CREATE SEQUENCE s4;
ALTER SEQUENCE s4 MAXVALUE 100;
PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP SEQUENCE s4;
CALL show_slow_log();
sql_text
[slow] TRUNCATE TABLE mysql.slow_log
[slow] CREATE TABLE t1 (a INT)
[slow] DROP TABLE t1
[slow] CREATE TABLE t2 (a INT)
[slow] DROP TABLE t3
[slow] CREATE TABLE t4 (a INT)
[slow] PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1'
[slow] DEALLOCATE PREPARE stmt
[slow] DROP TABLE t4
[slow] CREATE SEQUENCE s4
[slow] PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101'
[slow] DEALLOCATE PREPARE stmt
[slow] DROP SEQUENCE s4
#
# Expect all admin statements in the slow log (GLOBAL OFF,LOCAL ON,DEFAULT)
# In the original implementation, this combination disabled slow log for admin commands.
# However, instead of this exception in GLOBAL vs LOCAL variable behaviour,
# we should make max_system_variables.log_slow_admin_statements=0
# prevent enabling globally suppressed logging by setting the session variable to ON.
#
SET @@GLOBAL.log_slow_admin_statements=OFF;
SET @@SESSION.log_slow_admin_statements=ON;
SET log_slow_filter=DEFAULT;
TRUNCATE TABLE mysql.slow_log;
CREATE TABLE t1 (a INT);
CREATE INDEX t1a ON t1 (a);
DROP INDEX t1a ON t1;
DROP TABLE t1;
CREATE TABLE t2 (a INT);
ALTER TABLE t2 RENAME t2;
RENAME TABLE t2 TO t3;
DROP TABLE t3;
CREATE TABLE t4 (a INT);
PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP TABLE t4;
CREATE SEQUENCE s4;
ALTER SEQUENCE s4 MAXVALUE 100;
PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101';
EXECUTE stmt;
DEALLOCATE PREPARE stmt;
DROP SEQUENCE s4;
CALL show_slow_log();
sql_text
[slow] TRUNCATE TABLE mysql.slow_log
[slow] CREATE TABLE t1 (a INT)
[slow] CREATE INDEX t1a ON t1 (a)
[slow] DROP INDEX t1a ON t1
[slow] DROP TABLE t1
[slow] CREATE TABLE t2 (a INT)
[slow] ALTER TABLE t2 RENAME t2
[slow] RENAME TABLE t2 TO t3
[slow] DROP TABLE t3
[slow] CREATE TABLE t4 (a INT)
[slow] PREPARE stmt FROM 'ALTER TABLE t4 MODIFY a INT DEFAULT 1'
[slow] ALTER TABLE t4 MODIFY a INT DEFAULT 1
[slow] DEALLOCATE PREPARE stmt
[slow] DROP TABLE t4
[slow] CREATE SEQUENCE s4
[slow] ALTER SEQUENCE s4 MAXVALUE 100
[slow] PREPARE stmt FROM 'ALTER SEQUENCE s4 MAXVALUE=101'
[slow] ALTER SEQUENCE s4 MAXVALUE=101
[slow] DEALLOCATE PREPARE stmt
[slow] DROP SEQUENCE s4
#
# Start of 10.6 tests
#
#
# MDEV-32203 Raise notes when an index cannot be used on data type
# mismatch
#
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;
set global slow_query_log_file='MYSQLTEST_VARDIR/tmp/log_slow_debug-1.log';
FLUSH SLOW LOGS;
SELECT * FROM t1 WHERE a=10;
a
10
Warnings:
Note 1105 Cannot use key `a` part[0] for lookup: `test`.`t1`.`a` of type `varchar` = "10" of type `int`
EXPLAIN SELECT * FROM t1 WHERE a=10;
id select_type table type possible_keys key key_len ref rows Extra
1 SIMPLE t1 index a a 13 NULL 32 Using where; Using index
Warnings:
Note 1105 Cannot use key `a` part[0] for lookup: `test`.`t1`.`a` of type `varchar` = "10" of type `int`
FOUND 2 /# Warnings/ in log_slow_debug-1.log
FOUND 1 /# Note.*Cannot use key.*varchar.*10.*int/ in log_slow_debug-1.log
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;
id select_type table type possible_keys key key_len ref rows Extra
1 SIMPLE t1 index a a 13 NULL 32 Using where; Using index
Warnings:
Note 1105 Cannot use key `a` part[0] for lookup: `test`.`t1`.`a` of type `varchar` = "10" of type `int`
FOUND 1 /# Warnings/ in log_slow_debug-2.log
FOUND 1 /# Note.*Cannot use key.*varchar.*10.*int/ in log_slow_debug-2.log
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;
a
10
Warnings:
Note 1105 Cannot use key `a` part[0] for lookup: `test`.`t1`.`a` of type `varchar` = "10" of type `int`
EXPLAIN SELECT * FROM t1 WHERE a=10;
id select_type table type possible_keys key key_len ref rows Extra
1 SIMPLE t1 index a a 13 NULL 32 Using where; Using index
Warnings:
Note 1105 Cannot use key `a` part[0] for lookup: `test`.`t1`.`a` of type `varchar` = "10" of type `int`
NOT FOUND /# Warnings/ in log_slow_debug-3.log
NOT FOUND /# Note.*Cannot use key.*varchar.*10.*int/ in log_slow_debug-3.log
set @@global.slow_query_log_file= @org_slow_query_log_file;
DROP TABLE t1;
#
# MDEV-30820: slow log Rows_examined out of range
#
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";
SELECT * FROM tab_MDEV_30820 ORDER BY 1;
ID A
1 0
2 0
SET debug_dbug=@old_dbug;
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%";
rows_examined sql_text
18446744073708551615 SELECT * FROM tab_MDEV_30820 ORDER BY 1
drop table tab_MDEV_30820;
#
# End of 10.4 test
#
#
# Clean up
#
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;