mirror of
https://github.com/MariaDB/server.git
synced 2025-05-27 01:57:48 +03:00
f4a16558c8
being logged to slow query log The problem is that the execution time for a multi-statement stored procedure as a whole may not be accurate, and thus not be entered into the slow query log even if the total time exceeds long_query_time. The reason for this is that THD::utime_after_lock used for time calculation may be reset at the start of each new statement, possibly leaving the total SP execution equal to the time spent executing the last statement in the SP. This patch stores the utime on start of SP execution, and restores it on exit of SP execution. A test is added. mysql-test/suite/sys_vars/r/slow_query_log_func.result: New test results for #47905. mysql-test/suite/sys_vars/t/slow_query_log_func.test: New test case for #47905. sql/sp_head.cc: Save and restore the THD::utime_after_lock on entry and exit of execute_procedure().
63 lines
1.8 KiB
Plaintext
63 lines
1.8 KiB
Plaintext
# save
|
|
SET @global_slow_query_log = @@global.slow_query_log;
|
|
SET @global_log_output = @@global.log_output;
|
|
###############################################################################
|
|
# Begin the functionality testing for slow_query_log #
|
|
###############################################################################
|
|
|
|
SET @@session.long_query_time=1;
|
|
|
|
SET @@global.log_output = 'TABLE';
|
|
|
|
#=========================================
|
|
--echo '----When slow_query_log = OFF----'
|
|
#=========================================
|
|
|
|
SET @@global.slow_query_log = OFF;
|
|
TRUNCATE mysql.slow_log;
|
|
# The sleep is the slow query
|
|
SELECT sleep(2);
|
|
|
|
SELECT count(*) FROM mysql.slow_log;
|
|
|
|
#=========================================
|
|
--echo '----When slow_query_log = ON-----'
|
|
#=========================================
|
|
|
|
SET @@global.slow_query_log = ON;
|
|
TRUNCATE mysql.slow_log;
|
|
# The sleep is the slow query
|
|
SELECT sleep(2);
|
|
|
|
SELECT count(*) > 0 FROM mysql.slow_log;
|
|
|
|
|
|
#==========================================================================
|
|
--echo 'Bug#47905 stored procedures not logged correctly to slow query log'
|
|
#==========================================================================
|
|
# assumes logging to table turned on with long_query_time=1 as above
|
|
|
|
TRUNCATE mysql.slow_log;
|
|
|
|
DELIMITER //;
|
|
CREATE PROCEDURE p_test()
|
|
BEGIN
|
|
select sleep(2);
|
|
select 1;
|
|
END//
|
|
DELIMITER ;//
|
|
|
|
CALL p_test();
|
|
SELECT count(*) > 0 FROM mysql.slow_log;
|
|
DROP PROCEDURE p_test;
|
|
|
|
|
|
#restore
|
|
SET @@global.log_output = @global_log_output;
|
|
SET @global.slow_query_log = @global_slow_query_log;
|
|
|
|
###############################################################################
|
|
# End of the functionality test for slow_query_log #
|
|
###############################################################################
|
|
|