diff --git a/mysql-test/suite/sys_vars/r/slow_query_log_func.result b/mysql-test/suite/sys_vars/r/slow_query_log_func.result index d5485e2e6d7..eb7efe4a004 100644 --- a/mysql-test/suite/sys_vars/r/slow_query_log_func.result +++ b/mysql-test/suite/sys_vars/r/slow_query_log_func.result @@ -20,5 +20,21 @@ sleep(2) 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; diff --git a/mysql-test/suite/sys_vars/t/slow_query_log_func.test b/mysql-test/suite/sys_vars/t/slow_query_log_func.test index d2653f89de4..250d5210c46 100644 --- a/mysql-test/suite/sys_vars/t/slow_query_log_func.test +++ b/mysql-test/suite/sys_vars/t/slow_query_log_func.test @@ -31,6 +31,27 @@ 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; diff --git a/sql/sp_head.cc b/sql/sp_head.cc index 45cb4eebb09..8a626cabd90 100644 --- a/sql/sp_head.cc +++ b/sql/sp_head.cc @@ -1848,6 +1848,8 @@ sp_head::execute_procedure(THD *thd, List *args) { bool err_status= FALSE; uint params = m_pcont->context_var_count(); + /* Query start time may be reset in a multi-stmt SP; keep this for later. */ + ulonglong utime_before_sp_exec= thd->utime_after_lock; sp_rcontext *save_spcont, *octx; sp_rcontext *nctx = NULL; bool save_enable_slow_log= false; @@ -2040,6 +2042,7 @@ sp_head::execute_procedure(THD *thd, List *args) delete nctx; thd->spcont= save_spcont; + thd->utime_after_lock= utime_before_sp_exec; DBUG_RETURN(err_status); }