bk commit into 5.1 tree (petr:1.1952)

[Petr Chardin]

Below is the list of changes that have just been committed into a local
5.1 repository of cps. When cps 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.1952 05/12/05 16:31:11 petr@stripped +2 -0
  WL#1019 Select from logs: added comments, performed a cleanup

  sql/sql_class.h
    1.270 05/12/05 16:31:02 petr@stripped +5 -8
    cleanup

  sql/log.cc
    1.177 05/12/05 16:31:02 petr@stripped +189 -74
    cleanup, add comments

# 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:	petr
# Host:	owlet.
# Root:	/home/cps/mysql/devel/mysql-5.1-logs-curr

--- 1.176/sql/log.cc	2005-12-03 01:45:02 +03:00
+++ 1.177/sql/log.cc	2005-12-05 16:31:02 +03:00
@@ -101,15 +101,16 @@
 
   SYNOPSIS
     open_log_table()
-    tables     pointer to the TABLE_LIST structure which will be used
-               to open the general log. Later we'll use tables->table
-               to perform logging in log_general_to_csv()
+
+    log_type   type of the log table to open: LOG_GENERAL or LOG_SLOW
 
   DESCRIPTION
 
-    The function is used during the server startup. We open the log tables and
-    mark them as such. Log tables are open during the whole time, while
-    server is running.
+    The function opens a log table and marks it as such. Log tables are open
+    during the whole time, while server is running. Except for the mements
+    when they have to be reopened: during FLUSH LOGS and TRUNCATE. This
+    function is invoked directly only once during startup. All subsequent
+    calls happen through reopen_log_table(), which performs additional check.
 
   RETURN
     0 - ok
@@ -120,6 +121,7 @@
 {
   THD *log_thd, *curr= current_thd;
   TABLE_LIST *tables;
+  int error= 0;
   DBUG_ENTER("open_log_table");
 
   switch (log_type) {
@@ -165,19 +167,11 @@
   if (simple_open_n_lock_tables(log_thd, tables) ||
       tables->table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
       tables->table->file->ha_rnd_init(0))
-  {
-    if (curr)
-      curr->store_globals();
-    else
-    {
-      my_pthread_setspecific_ptr(THR_THD,  0);
-      my_pthread_setspecific_ptr(THR_MALLOC, 0);
-    }
-    DBUG_RETURN(1);
-  }
-
-  tables->table->locked_by_logger= TRUE;
+    error= 1;
+  else
+    tables->table->locked_by_logger= TRUE;
 
+  /* restore thread settings */
   if (curr)
     curr->store_globals();
   else
@@ -186,14 +180,33 @@
     my_pthread_setspecific_ptr(THR_MALLOC, 0);
   }
 
-  DBUG_RETURN(0);
+  DBUG_RETURN(error);
 }
 
+
 /*
-  this differs from open_log_table by a check, which we cannot
-  do in open_log_table since it is not yet valid at startup.
-  this code assumes that we have logger mutex locked
+  Reopen log table of a given type
+
+  SYNOPSIS
+    reopen_log_table()
+
+    log_type   type of the log table to open: LOG_GENERAL or LOG_SLOW
+
+  DESCRIPTION
+
+    The function is a wrapper around open_log_table(). It is used during
+    FLUSH LOGS and TRUNCATE of the log tables (i.e. when we need to close
+    and reopen them). The difference is in the check of the
+    logger.is_log_tables_initialized var, which can't be done in
+    open_log_table(), as it makes no sense during startup.
+
+    NOTE: this code assumes that we have logger mutex locked
+
+  RETURN
+    0 - ok
+    1 - open_log_table() returned an error
 */
+
 int reopen_log_table(uint log_type)
 {
   if (!logger.is_log_tables_initialized)
@@ -201,34 +214,41 @@
   return open_log_table(log_type);
 }
 
-/* log handlers */
+/* log event handlers */
 
 /*
   Log command to the general log table
 
   SYNOPSIS
     log_general_to_csv()
-    command           the type of the command being logged
+
+    event_time        command start timestamp
+    user_host         the pointer to the string with user@host info
+    user_host_len     length of the user_host string. this is computed once
+                      and passed to all general log event handlers
+    thread_id         Id of the thread, issued a query
+    command_type      the type of the command being logged
+    command_type_len  the length of the string above
+    sql_text          the very text of the query being executed
+    sql_text_len      the length of sql_text string
 
   DESCRIPTION
 
    Log given command to the general log table
 
   RETURN
-    0 - ok
-    1 - error occured
+    FALSE - ok
+    TRUE - error occured
 */
 
-
-static bool log_general_to_csv(const char *event_time, uint event_time_len,
-                               time_t time_t_event_time, const char *user_host,
-                               uint user_host_len, int thread_id, int server_id,
+static bool log_general_to_csv(time_t event_time, const char *user_host,
+                               uint user_host_len, int thread_id,
                                const char *command_type, uint command_type_len,
                                const char *sql_text, uint sql_text_len)
 {
   TABLE *table= general_log.table;
 
-  general_log_thd->start_time= time_t_event_time;
+  general_log_thd->start_time= event_time;
   /* set default value (which is CURRENT_TIMESTAMP) */
   table->field[0]->set_null();
 
@@ -254,14 +274,27 @@
   SYNOPSIS
     log_slow_to_csv()
     thd               THD of the query
+    current_time      current timestamp
+    query_start_arg   command start timestamp
+    user_host         the pointer to the string with user@host info
+    user_host_len     length of the user_host string. this is computed once
+                      and passed to all general log event handlers
+    query_time        Amount of time the query took to execute (in seconds)
+    lock_time         Amount of time the query was locked (in seconds)
+    is_command        The flag, which determines, whether the sql_text is a
+                      query or an administrator command (these are treated
+                      differently by the old logging routines)
+    sql_text          the very text of the query or administrator command
+                      processed
+    sql_text_len      the length of sql_text string
 
   DESCRIPTION
 
    Log a query to the slow log table
 
   RETURN
-    0 - ok
-    1 - error occured
+    FALSE - ok
+    TRUE - error occured
 */
 
 bool log_slow_to_csv(THD *thd, time_t current_time, time_t query_start_arg,
@@ -346,6 +379,9 @@
   return vprint_msg_to_log(level, format, args);
 }
 
+
+/* Wrapper around MYSQL_LOG::write() for slow log */
+
 bool log_slow_old(THD *thd, time_t current_time, time_t query_start_arg,
                   const char *user_host, uint user_host_len,
                   longlong query_time, longlong lock_time, bool is_command,
@@ -357,16 +393,20 @@
                               sql_text, sql_text_len);
 }
 
-bool log_general_old(const char *event_time, uint event_time_len,
-                     time_t time_t_event_time, const char *user_host,
-                     uint user_host_len, int thread_id, int server_id,
+
+/*
+   Wrapper around MYSQL_LOG::write() for general log. We need it since we
+   want all log event handlers to have the same signanture.
+*/
+
+bool log_general_old(time_t event_time, const char *user_host,
+                     uint user_host_len, int thread_id,
                      const char *command_type, uint command_type_len,
                      const char *sql_text, uint sql_text_len)
 {
-  return mysql_log.write(event_time, event_time_len, time_t_event_time,
-                         user_host, user_host_len, thread_id, server_id,
-                         command_type, command_type_len, sql_text,
-                         sql_text_len);
+  return mysql_log.write(event_time, user_host, user_host_len,
+                         thread_id, command_type, command_type_len,
+                         sql_text, sql_text_len);
 }
 
 void LOGGER::init_pthread_objects()
@@ -391,7 +431,24 @@
   (void) pthread_mutex_destroy(&LOCK_logger);
 }
 
-int LOGGER::error_log_print(enum loglevel level, const char *format,
+
+/*
+  Log error with all enabled log event handlers
+
+  SYNOPSIS
+    error_log_print()
+
+    level             The level of the error significance: NOTE,
+                      WARNING or ERROR.
+    format            format string for the error message
+    args              list of arguments forr the format string
+
+  RETURN
+    FALSE - ok
+    TRUE - error occured
+*/
+
+bool LOGGER::error_log_print(enum loglevel level, const char *format,
                             va_list args)
 {
   uint error= 0;
@@ -402,9 +459,26 @@
   while (*current_handler)
     error+= (*current_handler++)(level, format, args);
 
-  return error;
+  return error != 0;
 }
 
+
+/*
+  Log slow query with all enabled log event handlers
+
+  SYNOPSIS
+    slow_log_print()
+
+    thd               THD of the query being logged
+    query             The query being logged
+    query_length      The length of the query string
+    query_start_arg   Query start timestamp
+
+  RETURN
+    FALSE - ok
+    TRUE - error occured
+*/
+
 bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
                             time_t query_start_arg)
 {
@@ -476,11 +550,10 @@
   {
     char message_buff[MAX_LOG_BUFFER_SIZE];
     char user_host_buff[MAX_USER_HOST_SIZE];
-    char time_buff[MAX_TIME_SIZE];
     Security_context *sctx= thd->security_ctx;
     ulong id;
     uint message_buff_len= 0, user_host_len= 0;
-    uint time_buff_len= 0, command_name_len= 0;
+    uint command_name_len= 0;
 
     if (thd)
     {                                           /* Normal thread */
@@ -499,14 +572,6 @@
 
     lock();
     time_t current_time= time(NULL);
-    struct tm start;
-    localtime_r(&current_time, &start);
-
-    time_buff_len= my_snprintf(time_buff, MAX_TIME_SIZE,
-                               "%02d-%02d-%02d %2d:%02d:%02d",
-                               start.tm_year % 100, start.tm_mon + 1,
-                               start.tm_mday, start.tm_hour,
-                               start.tm_min, start.tm_sec);
 
     /* fill in user_host value */
     strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
@@ -525,9 +590,9 @@
       message_buff[0]= '\0';
 
     while (*current_handler)
-      error+= (*current_handler++) (time_buff, time_buff_len, current_time,
-                                    user_host_buff, user_host_len, id,
-                                    server_id, command_name[(uint) command],
+      error+= (*current_handler++) (current_time, user_host_buff,
+                                    user_host_len, id,
+                                    command_name[(uint) command],
                                     command_name_len, message_buff,
                                     message_buff_len);
     unlock();
@@ -2104,29 +2169,58 @@
 }
 
 /*
-  Write to normal (not rotable) log
-  This is the format for the 'normal' log.
+  Write a command to traditional general log file
+
+  SYNOPSIS
+    write()
+
+    event_time        command start timestamp
+    user_host         the pointer to the string with user@host info
+    user_host_len     length of the user_host string. this is computed once
+                      and passed to all general log  eventhandlers
+    thread_id         Id of the thread, issued a query
+    command_type      the type of the command being logged
+    command_type_len  the length of the string above
+    sql_text          the very text of the query being executed
+    sql_text_len      the length of sql_text string
+
+  DESCRIPTION
+
+   Log given command to to normal (not rotable) log file
+
+  RETURN
+    FASE - ok
+    TRUE - error occured
 */
 
-bool MYSQL_LOG::write(const char *event_time, uint event_time_len,
-                      time_t time_t_event_time, const char *user_host,
-                      uint user_host_len, int thread_id, int server_id,
+bool MYSQL_LOG::write(time_t event_time, const char *user_host,
+                      uint user_host_len, int thread_id,
                       const char *command_type, uint command_type_len,
                       const char *sql_text, uint sql_text_len)
 {
   char buff[32];
   uint length= 0;
-
-  VOID(pthread_mutex_lock(&LOCK_log));
+  char time_buff[MAX_TIME_SIZE];
+  struct tm start;
+  uint time_buff_len= 0;
 
   /* Test if someone closed between the is_open test and lock */
   if (is_open())
   {
     /* Note that my_b_write() assumes it knows the length for this */
-      if (time_t_event_time != last_time)
+      if (event_time != last_time)
       {
-        last_time= time_t_event_time;
-        if (my_b_write(&log_file, (byte*) event_time, event_time_len))
+        last_time= event_time;
+
+        localtime_r(&event_time, &start);
+
+        time_buff_len= my_snprintf(time_buff, MAX_TIME_SIZE,
+                                   "%02d%02d%02d %2d:%02d:%02d",
+                                   start.tm_year % 100, start.tm_mon + 1,
+                                   start.tm_mday, start.tm_hour,
+                                   start.tm_min, start.tm_sec);
+
+        if (my_b_write(&log_file, (byte*) &time_buff, time_buff_len))
           goto err;
       }
       else
@@ -2154,7 +2248,6 @@
       goto err;
   }
 
-  VOID(pthread_mutex_unlock(&LOCK_log));
   return FALSE;
 err:
 
@@ -2163,7 +2256,6 @@
     write_error= 1;
     sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
   }
-  VOID(pthread_mutex_unlock(&LOCK_log));
   return TRUE;
 }
 
@@ -2548,7 +2640,32 @@
 
 
 /*
-  Write to the slow query log.
+  Log a query to the traditional slow log file
+
+  SYNOPSIS
+    write()
+
+    thd               THD of the query
+    current_time      current timestamp
+    query_start_arg   command start timestamp
+    user_host         the pointer to the string with user@host info
+    user_host_len     length of the user_host string. this is computed once
+                      and passed to all general log event handlers
+    query_time        Amount of time the query took to execute (in seconds)
+    lock_time         Amount of time the query was locked (in seconds)
+    is_command        The flag, which determines, whether the sql_text is a
+                      query or an administrator command.
+    sql_text          the very text of the query or administrator command
+                      processed
+    sql_text_len      the length of sql_text string
+
+  DESCRIPTION
+
+   Log a query to the slow log file.
+
+  RETURN
+    FALSE - ok
+    TRUE - error occured
 */
 
 bool MYSQL_LOG::write(THD *thd, time_t current_time, time_t query_start_arg,
@@ -2562,7 +2679,6 @@
   if (!is_open())
     DBUG_RETURN(0);
 
-  VOID(pthread_mutex_lock(&LOCK_log));
   if (is_open())
   {						// Safety agains reopen
     int tmp_errno= 0;
@@ -2626,10 +2742,10 @@
     }
 
     /*
-       This info usd to show up randomly, depending on whether query_start_
-       checked the query start time or not. now we always write current
-       timestamp to the slow log
-   */
+      This info used to show up randomly, depending on whether the query
+      checked the query start time or not. now we always write current
+      timestamp to the slow log
+    */
     end= strmov(end, ",timestamp=");
     end= int10_to_str((long) current_time, end, 10);
 
@@ -2661,7 +2777,6 @@
       }
     }
   }
-  VOID(pthread_mutex_unlock(&LOCK_log));
   DBUG_RETURN(error);
 }
 

--- 1.269/sql/sql_class.h	2005-12-03 01:45:05 +03:00
+++ 1.270/sql/sql_class.h	2005-12-05 16:31:02 +03:00
@@ -183,12 +183,10 @@
                                  longlong lock_time, bool is_command,
                                  const char *sql_text, uint sql_text_len);
 
-typedef bool (*general_log_handler)(const char *event_time,
-                                    uint event_time_len,
-                                    time_t time_t_event_time,
+typedef bool (*general_log_handler)(time_t event_time,
                                     const char *user_host,
                                     uint user_host_len, int thread_id,
-                                    int server_id, const char *command_type,
+                                    const char *command_type,
                                     uint command_type_len,
                                     const char *sql_text, uint sql_text_len);
 
@@ -227,7 +225,7 @@
   void unlock();
   void init_pthread_objects();
   void cleanup();
-  int error_log_print(enum loglevel level, const char *format,
+  bool error_log_print(enum loglevel level, const char *format,
                       va_list args);
   bool slow_log_print(THD *thd, const char *query, uint query_length,
                       time_t query_start_arg);
@@ -374,9 +372,8 @@
                        const char *log_name);
   void new_file(bool need_lock);
   /* log a command to the old-fashioned general log */
-  bool write(const char *event_time, uint event_time_len,
-             time_t time_t_event_time, const char *user_host,
-             uint user_host_len, int thread_id, int server_id,
+  bool write(time_t event_time, const char *user_host,
+             uint user_host_len, int thread_id,
              const char *command_type, uint command_type_len,
              const char *sql_text, uint sql_text_len);