Skip to content

Commit

Permalink
MDEV-11552 Queries executed by event scheduler are written to slow lo…
Browse files Browse the repository at this point in the history
…g incorrectly or not written at all

because thd->update_server_status() is used to measure the query time
for the slow log (not only to set protocol level flags),
it needs to be called also when the server isn't going to send
anything to the client.
  • Loading branch information
vuvova committed Dec 16, 2016
1 parent 211cf93 commit e86580c
Show file tree
Hide file tree
Showing 3 changed files with 45 additions and 5 deletions.
12 changes: 12 additions & 0 deletions mysql-test/r/events_slowlog.result
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
set @event_scheduler_save= @@global.event_scheduler;
set @slow_query_log_save= @@global.slow_query_log;
set global event_scheduler= on;
set global slow_query_log= on;
set global long_query_time=0.2;
create table t1 (i int);
insert into t1 values (0);
create event ev on schedule at CURRENT_TIMESTAMP + INTERVAL 1 second do update t1 set i=1+sleep(0.5);
drop table t1;
set global event_scheduler= @event_scheduler_save;
set global slow_query_log= @slow_query_log_save;
set global long_query_time= @@session.long_query_time;
28 changes: 28 additions & 0 deletions mysql-test/t/events_slowlog.test
Original file line number Diff line number Diff line change
@@ -0,0 +1,28 @@
--source include/not_embedded.inc
#
# MDEV-11552 Queries executed by event scheduler are written to slow log incorrectly or not written at all
#
set @event_scheduler_save= @@global.event_scheduler;
set @slow_query_log_save= @@global.slow_query_log;

set global event_scheduler= on;
set global slow_query_log= on;
set global long_query_time=0.2;

create table t1 (i int);
insert into t1 values (0);
create event ev on schedule at CURRENT_TIMESTAMP + INTERVAL 1 second do update t1 set i=1+sleep(0.5);

--let wait_condition= select i from t1 where i > 0
--source include/wait_condition.inc

--let SEARCH_FILE = `SELECT @@slow_query_log_file`
--let SEARCH_PATTERN= update t1 set i=1
--let SEARCH_RANGE= -1000
--source include/search_pattern_in_file.inc

drop table t1;

set global event_scheduler= @event_scheduler_save;
set global slow_query_log= @slow_query_log_save;
set global long_query_time= @@session.long_query_time;
10 changes: 5 additions & 5 deletions sql/sp_head.cc
Original file line number Diff line number Diff line change
Expand Up @@ -3146,18 +3146,18 @@ sp_instr_stmt::execute(THD *thd, uint *nextp)
thd->query_length()) <= 0)
{
res= m_lex_keeper.reset_lex_and_exec_core(thd, nextp, FALSE, this);
bool log_slow= !res && thd->enable_slow_log;

if (thd->stmt_da->is_eof())
{
/* Finalize server status flags after executing a statement. */
/* Finalize server status flags after executing a statement. */
if (log_slow || thd->stmt_da->is_eof())
thd->update_server_status();

if (thd->stmt_da->is_eof())
thd->protocol->end_statement();
}

query_cache_end_of_result(thd);

if (!res && unlikely(thd->enable_slow_log))
if (log_slow)
log_slow_statement(thd);
}
else
Expand Down

0 comments on commit e86580c

Please sign in to comment.