When a stored routine calls an "administrative" command such as OPTIMIZE TABLE, ANALYZE TABLE, ALTER TABLE, CREATE/DROP INDEX, etc. the effective value of log_slow_sp_statements is reset to that of log_slow_admin_statements.
More specifically, mysql_execute_command() assigns the value of opt_log_slow_admin_statements to thd->enable_slow_log before execution of an administrative command. The original value of the->enable_slow_log is not restored back until the next statement execution. This becomes a problem for "substatements" of a stored routine, since the code relies on the->enable_slow_log to decide if log_slow_statement() should be called for individual statements in a stored routine.
As a result, with log_slow_sp_statements ON and log_slow_admin_statements OFF, the first administrative command in a stored routine will reset slow logging for all subsequent statements in that routine.
Conversely, with log_slow_sp_statements OFF and log_slow_admin_statements ON, the first administrative statement in a stored routine will turn slow logging on for all subsequent statements in that routine.
Steps to reproduce:
1. ./mysqld --log-slow-admin-statements=0
2. create the following table and SP:
CREATE TABLE t1(a int);
delimiter //
CREATE PROCEDURE test() BEGIN INSERT INTO t1 VALUES(0); CREATE INDEX i ON t1(a); INSERT INTO t1 VALUES(1); END//
delimiter ;
3. in a debugger, set a breakpoint on log_slow_statement()
4. execute "call test();"
5. log_slow_statement() will only be called for INSERT before CREATE INDEX, but not for the one after it.
When a stored routine calls an "administrative" command such as OPTIMIZE TABLE, ANALYZE TABLE, ALTER TABLE, CREATE/DROP INDEX, etc. the effective value of log_slow_ sp_statements is reset to that of log_slow_ admin_statement s.
More specifically, mysql_execute_ command( ) assigns the value of opt_log_ slow_admin_ statements to thd->enable_ slow_log before execution of an administrative command. The original value of the->enable_ slow_log is not restored back until the next statement execution. This becomes a problem for "substatements" of a stored routine, since the code relies on the->enable_ slow_log to decide if log_slow_ statement( ) should be called for individual statements in a stored routine.
As a result, with log_slow_ sp_statements ON and log_slow_ admin_statement s OFF, the first administrative command in a stored routine will reset slow logging for all subsequent statements in that routine.
Conversely, with log_slow_ sp_statements OFF and log_slow_ admin_statement s ON, the first administrative statement in a stored routine will turn slow logging on for all subsequent statements in that routine.
Steps to reproduce:
1. ./mysqld --log-slow- admin-statement s=0
2. create the following table and SP:
CREATE TABLE t1(a int);
delimiter //
CREATE PROCEDURE test() BEGIN INSERT INTO t1 VALUES(0); CREATE INDEX i ON t1(a); INSERT INTO t1 VALUES(1); END//
delimiter ;
3. in a debugger, set a breakpoint on log_slow_ statement( )
4. execute "call test();"
5. log_slow_ statement( ) will only be called for INSERT before CREATE INDEX, but not for the one after it.