| Bug #59861 | why does log_slow_statement call thd_proc_info twice? | ||
|---|---|---|---|
| Submitted: | 1 Feb 2011 1:50 | Modified: | 7 Mar 2011 23:18 |
| Reporter: | Mark Callaghan | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Logging | Severity: | S3 (Non-critical) |
| Version: | 5.1, 5.5, trunk | OS: | Any |
| Assigned to: | Jon Olav Hauglid | CPU Architecture: | Any |
| Tags: | log, query, slow | ||
[1 Feb 2011 5:02]
Valeriy Kravchuk
Verified by code review.
[3 Feb 2011 9:03]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/130303 3300 Jon Olav Hauglid 2011-02-03 Bug #59861 why does log_slow_statement call thd_proc_info twice? This patch removes an extraneous thd_proc_info(thd, "logging slow query") call from low_slow_statement(). The removed call was from before it was decided to actually log the query to the slow log. No test case added.
[3 Feb 2011 9:13]
Magne Mæhre
Ok to push
[7 Feb 2011 11:49]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/130557 3603 Jon Olav Hauglid 2011-02-07 Bug #59861 why does log_slow_statement call thd_proc_info twice? This patch removes an extraneous thd_proc_info(thd, "logging slow query") call from low_slow_statement(). The removed call was from before it was decided to actually log the query to the slow log. No test case added.
[7 Feb 2011 11:50]
Bugs System
Pushed into mysql-trunk 5.6.2 (revid:jon.hauglid@oracle.com-20110207114918-m0a336hi7wav0wmt) (version source revid:jon.hauglid@oracle.com-20110207114918-m0a336hi7wav0wmt) (merge vers: 5.6.2) (pib:24)
[7 Mar 2011 23:18]
Paul DuBois
Code cleanup. No user impact. No changelog entry needed.
[7 Mar 2011 23:20]
Paul DuBois
CHANGESET - http://lists.mysql.com/commits/130557
[29 Oct 2011 10:14]
MySQL Verification Team
Seems thd->current_utime() is called prematurely also. I've noted that in a new internal bug report.
Description: Why does log_slow_statement use this twice? Once should be enough. thd_proc_info(thd, "logging slow query"); ------ void log_slow_statement(THD *thd) { DBUG_ENTER("log_slow_statement"); /* The following should never be true with our current code base, but better to keep this here so we don't accidently try to log a statement in a trigger or stored function */ if (unlikely(thd->in_sub_stmt)) DBUG_VOID_RETURN; // Don't set time for sub stmt /* Do not log administrative statements unless the appropriate option is set. */ if (thd->enable_slow_log) { ulonglong end_utime_of_query= thd->current_utime(); thd_proc_info(thd, "logging slow query"); if (((thd->server_status & SERVER_QUERY_WAS_SLOW) || ((thd->server_status & (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) && opt_log_queries_not_using_indexes && !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) && thd->examined_row_count >= thd->variables.min_examined_row_limit) { thd_proc_info(thd, "logging slow query"); thd->status_var.long_query_count++; slow_log_print(thd, thd->query(), thd->query_length(), end_utime_of_query); } } DBUG_VOID_RETURN; } How to repeat: read the source in sql/sql_parse.cc Suggested fix: remove one of the calls