Bug #8475 If multi-query: query does not get into slow query log if it's not last
Submitted: 12 Feb 2005 14:19 Modified: 8 Mar 2005 0:35
Reporter: Guilhem Bichot Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:4.1 OS:Any (all)
Assigned to: Jim Winstead CPU Architecture:Any

[12 Feb 2005 14:19] Guilhem Bichot
Description:
Run server with --log-slow.
Due to how code is written in sql_parse.cc, if you issue a multi-query:
delimiter /;
insert into t values(1000); insert into t values(2000)/
(imagine each insert takes a very long time),
then only the second insert will get into slow query log.
Reasons for the problem:
1) (unsure) how query timing is done (when start_time and time_after_lock are set)
2) (sure) when slow logging happens, thd->query is used and points to last query.
In Slow query log you get only this:
# Time: 050212 15:07:53
# User@Host: [root] @ localhost []
# Query_time: <etc>
insert into t values(2000);

How to repeat:
Run server with --log-slow.
Issue a multi-query in 'mysql' command line client:
delimiter /;
slowquery1; slowquery2/
and observe that only slowquery2 gets in slow log.
[23 Feb 2005 0:52] Jim Winstead
Fix pushed, will be in 4.1.11.
[8 Mar 2005 0:35] Paul Dubois
Noted in 4.1.11 changelog.