diff --git a/mysql-test/r/log_slow_debug.result b/mysql-test/r/log_slow_debug.result new file mode 100644 index 00000000000..48314f85a1c --- /dev/null +++ b/mysql-test/r/log_slow_debug.result @@ -0,0 +1,137 @@ +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 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 @@GLOBAL.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; +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 +# +# Expect all admin statements in the slow log (ON,admin) +# +SET @@GLOBAL.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; +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] ALTER TABLE t4 MODIFY a INT DEFAULT 1 +# +# Expect none of admin DDL statements in the slow log (ON,filesort) +# +SET @@GLOBAL.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; +CALL show_slow_log(); +sql_text +# +# Expect none of admin statements in the slow log (OFF,DEFAULT) +# +SET @@GLOBAL.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; +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] 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] DEALLOCATE PREPARE stmt +[slow] DROP TABLE t4 +# +# Clean up +# +SET SESSION debug_dbug="-d,simulate_slow_query"; +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; diff --git a/mysql-test/t/log_slow_debug.test b/mysql-test/t/log_slow_debug.test new file mode 100644 index 00000000000..35b5b93423d --- /dev/null +++ b/mysql-test/t/log_slow_debug.test @@ -0,0 +1,126 @@ +-- source include/have_debug.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 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 @@GLOBAL.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; +CALL show_slow_log(); + + +--echo # +--echo # Expect all admin statements in the slow log (ON,admin) +--echo # + +SET @@GLOBAL.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; +CALL show_slow_log(); + + +--echo # +--echo # Expect none of admin DDL statements in the slow log (ON,filesort) +--echo # + +SET @@GLOBAL.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; +CALL show_slow_log(); + + +--echo # +--echo # Expect none of admin statements in the slow log (OFF,DEFAULT) +--echo # + +SET @@GLOBAL.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; +CALL show_slow_log(); + + +--echo # +--echo # Clean up +--echo # + +SET SESSION debug_dbug="-d,simulate_slow_query"; +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; diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc index 04ea7dad8bb..099d3cd4bf1 100644 --- a/sql/sql_parse.cc +++ b/sql/sql_parse.cc @@ -2047,6 +2047,9 @@ void log_slow_statement(THD *thd) if (!thd->enable_slow_log) goto end; // E.g. SP statement + DBUG_EXECUTE_IF("simulate_slow_query", + thd->server_status|= SERVER_QUERY_WAS_SLOW;); + if (((thd->server_status & SERVER_QUERY_WAS_SLOW) || ((thd->server_status & (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&