Added THD::utime_after_query to avoid calling current_utime() twice for every end-of-query

Increment long_query_count also if thd->variables.log_slow_rate_limit is used
Added new state "Writing to binlog"


sql/sql_class.h:
  Added THD::utime_after_query to avoid calling current_utime() twice for every end-of-query
sql/sql_parse.cc:
  Increment long_query_count also if thd->variables.log_slow_rate_limit is used
  Removed extra calls to thd_proc_info(thd, "logging slow query") and thd->current_utime();
sql/sql_table.cc:
  Added new state "Writing to binlog"

sql/sql_class.h

@@ -1685,7 +1685,7 @@ class THD :public Statement,
   my_hrtime_t user_time;
   // track down slow pthread_create
   ulonglong  prior_thr_create_utime, thr_create_utime;
-  ulonglong  start_utime, utime_after_lock;
+  ulonglong  start_utime, utime_after_lock, utime_after_query;
 
   // Process indicator
   struct {
@@ -2488,8 +2488,8 @@ class THD :public Statement,
   */
   void update_server_status()
   {
-    ulonglong end_utime_of_query= current_utime();
-    if (end_utime_of_query > utime_after_lock + variables.long_query_time)
+    utime_after_query= current_utime();
+    if (utime_after_query > utime_after_lock + variables.long_query_time)
       server_status|= SERVER_QUERY_WAS_SLOW;
   }
   inline ulonglong found_rows(void)

sql/sql_parse.cc

@@ -1483,9 +1483,18 @@ void log_slow_statement(THD *thd)
     DBUG_VOID_RETURN;                           // Don't set time for sub stmt
 
   /* Follow the slow log filter configuration. */ 
-  if (!(thd->variables.log_slow_filter & thd->query_plan_flags))
+  if (!thd->enable_slow_log ||
+      !(thd->variables.log_slow_filter & thd->query_plan_flags))
     DBUG_VOID_RETURN; 
  
+  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->status_var.long_query_count++;
     /*
       If rate limiting of slow log writes is enabled, decide whether to log
       this query to the log or not.
@@ -1494,27 +1503,10 @@ void log_slow_statement(THD *thd)
         (global_query_id % thd->variables.log_slow_rate_limit) != 0)
       DBUG_VOID_RETURN;
 
-  /*
-    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);
-    }
+                   thd->utime_after_query);
+    thd_proc_info(thd, 0);
   }
   DBUG_VOID_RETURN;
 }

sql/sql_table.cc

@@ -1828,6 +1828,7 @@ int write_bin_log(THD *thd, bool clear_error,
   if (mysql_bin_log.is_open())
   {
     int errcode= 0;
+    thd_proc_info(thd, "Writing to binlog");
     if (clear_error)
       thd->clear_error();
     else
@@ -1835,6 +1836,7 @@ int write_bin_log(THD *thd, bool clear_error,
     error= thd->binlog_query(THD::STMT_QUERY_TYPE,
                              query, query_length, is_trans, FALSE, FALSE,
                              errcode);
+    thd_proc_info(thd, 0);
   }
   return error;
 }