mirror of
https://github.com/MariaDB/server.git
synced 2025-08-27 13:04:36 +03:00
c1a6dc5084
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.
41 lines
887 B
Plaintext
41 lines
887 B
Plaintext
SET @global_slow_query_log = @@global.slow_query_log;
|
|
SET @global_log_output = @@global.log_output;
|
|
SET @@session.long_query_time=1;
|
|
SET @@global.log_output = 'TABLE';
|
|
'----When slow_query_log = OFF----'
|
|
SET @@global.slow_query_log = OFF;
|
|
TRUNCATE mysql.slow_log;
|
|
SELECT sleep(2);
|
|
sleep(2)
|
|
0
|
|
SELECT count(*) FROM mysql.slow_log;
|
|
count(*)
|
|
0
|
|
'----When slow_query_log = ON-----'
|
|
SET @@global.slow_query_log = ON;
|
|
TRUNCATE mysql.slow_log;
|
|
SELECT sleep(2);
|
|
sleep(2)
|
|
0
|
|
SELECT count(*) > 0 FROM mysql.slow_log;
|
|
count(*) > 0
|
|
1
|
|
'Bug#47905 stored procedures not logged correctly to slow query log'
|
|
TRUNCATE mysql.slow_log;
|
|
CREATE PROCEDURE p_test()
|
|
BEGIN
|
|
select sleep(2);
|
|
select 1;
|
|
END//
|
|
CALL p_test();
|
|
sleep(2)
|
|
0
|
|
1
|
|
1
|
|
SELECT count(*) > 0 FROM mysql.slow_log;
|
|
count(*) > 0
|
|
1
|
|
DROP PROCEDURE p_test;
|
|
SET @@global.log_output = @global_log_output;
|
|
SET @global.slow_query_log = @global_slow_query_log;
|