bk commit into 5.1 tree (andrey:1.2150) BUG#16426

[ahristov]

Below is the list of changes that have just been committed into a local
5.1 repository of andrey. When andrey does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html

ChangeSet
  1.2150 06/02/21 04:24:37 andrey@lmy004. +5 -0
  fix for bug #16426
  (first round, no test case, will be added with later CS commit)

  sql/sql_parse.cc
    1.523 06/02/21 04:24:27 andrey@lmy004. +2 -0
    let us see it in the debug log

  sql/sp_head.h
    1.81 06/02/21 04:24:27 andrey@lmy004. +2 -1
    add a new constant for slow queries. SP by default does not log slow queries in the
    body just the whole CALL could be considered as slow if taking too much time and called
    directly from the user

  sql/sp_head.cc
    1.205 06/02/21 04:24:26 andrey@lmy004. +15 -2
    allow thd->enable_slow_log to be TRUE if only m_flags & sp_head::LOG_SLOW_STATEMENTS
    Because usually enable_slow_log is 1 in user mode, this second check is needed
    backup the mode otherwise.

  sql/event_timed.cc
    1.34 06/02/21 04:24:26 andrey@lmy004. +2 -0
    enable slow logging for the anonymous SP

  sql/event_executor.cc
    1.31 06/02/21 04:24:26 andrey@lmy004. +2 -1
    enable slow logging

# This is a BitKeeper patch.  What follows are the unified diffs for the
# set of deltas contained in the patch.  The rest of the patch, the part
# that BitKeeper cares about, is below these diffs.
# User:	andrey
# Host:	lmy004.
# Root:	/work/mysql-5.1-bug17494

--- 1.522/sql/sql_parse.cc	2006-02-15 17:12:20 +01:00
+++ 1.523/sql/sql_parse.cc	2006-02-21 04:24:27 +01:00
@@ -2111,6 +2111,7 @@ bool dispatch_command(enum enum_server_c
 
 void log_slow_statement(THD *thd)
 {
+  DBUG_ENTER("log_slow_statement");
   time_t start_of_query;
 
   /*
@@ -2142,6 +2143,7 @@ void log_slow_statement(THD *thd)
       slow_log_print(thd, thd->query, thd->query_length, start_of_query);
     }
   }
+  DBUG_VOID_RETURN;
 }
 
 

--- 1.30/sql/event_executor.cc	2006-02-16 01:27:30 +01:00
+++ 1.31/sql/event_executor.cc	2006-02-21 04:24:26 +01:00
@@ -272,7 +272,7 @@ init_event_thread(THD* thd)
   my_net_init(&thd->net, 0);
   thd->net.read_timeout = slave_net_timeout;
   thd->slave_thread= 0;
-  thd->options= OPTION_AUTO_IS_NULL;
+  thd->options= OPTION_AUTO_IS_NULL | OPTION_UPDATE_LOG;
   thd->client_capabilities= CLIENT_LOCAL_FILES;
   thd->real_id=pthread_self();
   VOID(pthread_mutex_lock(&LOCK_thread_count));
@@ -707,6 +707,7 @@ event_executor_worker(void *event_void)
   thd= current_thd;
 #endif
 
+  thd->enable_slow_log= TRUE;
   {
     int ret;
     sql_print_information("SCHEDULER: Executing event %s.%s of %s [EXPR:%d]",

--- 1.33/sql/event_timed.cc	2006-02-16 13:11:06 +01:00
+++ 1.34/sql/event_timed.cc	2006-02-21 04:24:26 +01:00
@@ -1116,6 +1116,8 @@ event_timed::execute(THD *thd, MEM_ROOT 
   {
     List<Item> empty_item_list;
     empty_item_list.empty();
+    if (thd->enable_slow_log)
+      sphead->m_flags|= sp_head::LOG_SLOW_STATEMENTS;
     ret= sphead->execute_procedure(thd, &empty_item_list);
   }
   else

--- 1.204/sql/sp_head.cc	2006-02-18 23:37:51 +01:00
+++ 1.205/sql/sp_head.cc	2006-02-21 04:24:26 +01:00
@@ -1412,6 +1412,7 @@ sp_head::execute_procedure(THD *thd, Lis
   uint params = m_pcont->context_pvars();
   sp_rcontext *save_spcont, *octx;
   sp_rcontext *nctx = NULL;
+  bool save_enable_slow_log;
   DBUG_ENTER("sp_head::execute_procedure");
   DBUG_PRINT("info", ("procedure %s", m_name.str));
 
@@ -1510,12 +1511,20 @@ sp_head::execute_procedure(THD *thd, Lis
 
     DBUG_PRINT("info",(" %.*s: eval args done", m_name.length, m_name.str));
   }
-
+  if (thd->enable_slow_log && !(m_flags & LOG_SLOW_STATEMENTS))
+  {
+    DBUG_PRINT("info", ("Disabling slow log for the execution"));
+    save_enable_slow_log= thd->enable_slow_log;
+    thd->enable_slow_log= FALSE;
+  }
   thd->spcont= nctx;
-
+  
   if (!err_status)
     err_status= execute(thd);
 
+  if (thd->enable_slow_log && !(m_flags & LOG_SLOW_STATEMENTS))
+    thd->enable_slow_log= save_enable_slow_log;
+
   /*
     In the case when we weren't able to employ reuse mechanism for
     OUT/INOUT paranmeters, we should reallocate memory. This
@@ -2295,7 +2304,11 @@ sp_instr_stmt::execute(THD *thd, uint *n
     if (query_cache_send_result_to_client(thd,
 					  thd->query, thd->query_length) <= 0)
     {
+      if (unlikely(thd->enable_slow_log))
+        thd->set_time();
       res= m_lex_keeper.reset_lex_and_exec_core(thd, nextp, FALSE, this);
+      if (!res && unlikely(thd->enable_slow_log))
+        log_slow_statement(thd);
       query_cache_end_of_result(thd);
     }
     else

--- 1.80/sql/sp_head.h	2006-02-09 11:34:35 +01:00
+++ 1.81/sql/sp_head.h	2006-02-21 04:24:27 +01:00
@@ -124,7 +124,8 @@ public:
     IS_INVOKED= 32,             // Is set if this sp_head is being used
     HAS_SET_AUTOCOMMIT_STMT= 64,// Is set if a procedure with 'set autocommit'
     /* Is set if a procedure with COMMIT (implicit or explicit) | ROLLBACK */
-    HAS_COMMIT_OR_ROLLBACK= 128
+    HAS_COMMIT_OR_ROLLBACK= 128,
+    LOG_SLOW_STATEMENTS= 256
   };
 
   /* TYPE_ENUM_FUNCTION, TYPE_ENUM_PROCEDURE or TYPE_ENUM_TRIGGER */