MySQL Lists are EOL. Please join:

List:Commits« Previous MessageNext Message »
From:Konstantin Osipov Date:October 19 2010 6:59pm
Subject:bzr commit into mysql-5.5-runtime branch (kostja:3167) Bug#57058
View as plain text  
#At file:///opt/local/work/5.5-runtime-57058/ based on revid:kostja@stripped

 3167 Konstantin Osipov	2010-10-19
      Implement a fix for Bug#57058 -- send SERVER_QUERY_WAS_SLOW over
      network when a query was slow.
      
      When a query is slow, sent a special flag to the client
      indicating this fact.
      
      Add a test case.
     @ include/mysql_com.h
        Clear SERVER_QUERY_WAS_SLOW at end of each statement.
        Since this patch removes the technique when 
        thd->server_status is modified briefly only to
        execute my_eof(), reset more server status
        bit that may remain in the status from
        execution of the previous statement.
     @ sql/protocol.cc
        Always use thd->server_status to 
        in net_* functions to send the latest
        status to the client.
     @ sql/sp_head.cc
        Calculate if a query was slow before
        sending EOF packet.
     @ sql/sql_cursor.cc
        Remove juggling with thd->server_status.
        The extra status bits are reset at
        start of the next statement.
     @ sql/sql_db.cc
        Remove juggling with thd->server_status.
        The extra status bits are reset at
        start of the next statement.
     @ sql/sql_error.cc
        Remove m_server_status member,
        it's not really part of the Diagnostics_area.
     @ sql/sql_error.h
        Remove server_status member, it's
        not part of the Diagnostics_area.
        The associated hack is removed as well.
     @ sql/sql_parse.cc
        Do not calculate if a query was
        slow twice. Use a status flag in thd->server_status.
     @ tests/mysql_client_test.c
        Add a test case for Bug#57058.
        Check that the status is present
        at the client, when sent.

    modified:
      include/mysql_com.h
      sql/protocol.cc
      sql/sp_head.cc
      sql/sql_class.h
      sql/sql_cursor.cc
      sql/sql_db.cc
      sql/sql_error.cc
      sql/sql_error.h
      sql/sql_parse.cc
      tests/mysql_client_test.c
=== modified file 'include/mysql_com.h'
--- a/include/mysql_com.h	2010-08-16 15:16:07 +0000
+++ b/include/mysql_com.h	2010-10-19 18:59:12 +0000
@@ -255,7 +255,11 @@ enum enum_server_command
 #define SERVER_STATUS_CLEAR_SET (SERVER_QUERY_NO_GOOD_INDEX_USED| \
                                  SERVER_QUERY_NO_INDEX_USED|\
                                  SERVER_MORE_RESULTS_EXISTS|\
-                                 SERVER_STATUS_METADATA_CHANGED)
+                                 SERVER_STATUS_METADATA_CHANGED |\
+                                 SERVER_QUERY_WAS_SLOW |\
+                                 SERVER_STATUS_DB_DROPPED |\
+                                 SERVER_STATUS_CURSOR_EXISTS|\
+                                 SERVER_STATUS_LAST_ROW_SENT)
 
 #define MYSQL_ERRMSG_SIZE	512
 #define NET_READ_TIMEOUT	30		/* Timeout on read */

=== modified file 'sql/protocol.cc'
--- a/sql/protocol.cc	2010-08-09 08:32:50 +0000
+++ b/sql/protocol.cc	2010-10-19 18:59:12 +0000
@@ -505,11 +505,11 @@ void Protocol::end_statement()
                       thd->stmt_da->get_sqlstate());
     break;
   case Diagnostics_area::DA_EOF:
-    error= send_eof(thd->stmt_da->server_status(),
+    error= send_eof(thd->server_status,
                     thd->stmt_da->statement_warn_count());
     break;
   case Diagnostics_area::DA_OK:
-    error= send_ok(thd->stmt_da->server_status(),
+    error= send_ok(thd->server_status,
                    thd->stmt_da->statement_warn_count(),
                    thd->stmt_da->affected_rows(),
                    thd->stmt_da->last_insert_id(),

=== modified file 'sql/sp_head.cc'
--- a/sql/sp_head.cc	2010-10-12 12:19:33 +0000
+++ b/sql/sp_head.cc	2010-10-19 18:59:12 +0000
@@ -3075,6 +3075,9 @@ sp_instr_stmt::execute(THD *thd, uint *n
     {
       res= m_lex_keeper.reset_lex_and_exec_core(thd, nextp, FALSE, this);
 
+      /* Finalize server status flags after executing a statement. */
+      thd->update_server_status();
+
       if (thd->stmt_da->is_eof())
         thd->protocol->end_statement();
 

=== modified file 'sql/sql_class.h'
--- a/sql/sql_class.h	2010-09-20 14:17:32 +0000
+++ b/sql/sql_class.h	2010-10-19 18:59:12 +0000
@@ -2211,6 +2211,20 @@ public:
   }
   void set_time_after_lock()  { utime_after_lock= my_micro_time(); }
   ulonglong current_utime()  { return my_micro_time(); }
+  /**
+   Update server status after execution of a top level statement.
+
+   Currently only checks if a query was slow, and assigns
+   the status accordingly.
+   Evaluate the current time, and if it exceeds the long-query-time
+   setting, mark the query as slow.
+  */
+  void update_server_status()
+  {
+    ulonglong end_utime_of_query= current_utime();
+    if (end_utime_of_query > utime_after_lock + variables.long_query_time)
+      server_status|= SERVER_QUERY_WAS_SLOW;
+  }
   inline ulonglong found_rows(void)
   {
     return limit_found_rows;

=== modified file 'sql/sql_cursor.cc'
--- a/sql/sql_cursor.cc	2010-07-29 12:32:11 +0000
+++ b/sql/sql_cursor.cc	2010-10-19 18:59:12 +0000
@@ -277,7 +277,6 @@ int Materialized_cursor::open(JOIN *join
     rc= result->send_result_set_metadata(item_list, Protocol::SEND_NUM_ROWS);
     thd->server_status|= SERVER_STATUS_CURSOR_EXISTS;
     result->send_eof();
-    thd->server_status&= ~SERVER_STATUS_CURSOR_EXISTS;
   }
   return rc;
 }
@@ -318,12 +317,10 @@ void Materialized_cursor::fetch(ulong nu
   case 0:
     thd->server_status|= SERVER_STATUS_CURSOR_EXISTS;
     result->send_eof();
-    thd->server_status&= ~SERVER_STATUS_CURSOR_EXISTS;
     break;
   case HA_ERR_END_OF_FILE:
     thd->server_status|= SERVER_STATUS_LAST_ROW_SENT;
     result->send_eof();
-    thd->server_status&= ~SERVER_STATUS_LAST_ROW_SENT;
     close();
     break;
   default:

=== modified file 'sql/sql_db.cc'
--- a/sql/sql_db.cc	2010-07-19 08:27:53 +0000
+++ b/sql/sql_db.cc	2010-10-19 18:59:12 +0000
@@ -866,7 +866,6 @@ bool mysql_rm_db(THD *thd,char *db,bool 
     thd->clear_error();
     thd->server_status|= SERVER_STATUS_DB_DROPPED;
     my_ok(thd, (ulong) deleted);
-    thd->server_status&= ~SERVER_STATUS_DB_DROPPED;
   }
   else if (mysql_bin_log.is_open())
   {

=== modified file 'sql/sql_error.cc'
--- a/sql/sql_error.cc	2010-07-30 15:28:36 +0000
+++ b/sql/sql_error.cc	2010-10-19 18:59:12 +0000
@@ -365,7 +365,6 @@ Diagnostics_area::set_ok_status(THD *thd
   if (is_error() || is_disabled())
     return;
 
-  m_server_status= thd->server_status;
   m_statement_warn_count= thd->warning_info->statement_warn_count();
   m_affected_rows= affected_rows_arg;
   m_last_insert_id= last_insert_id_arg;
@@ -395,7 +394,6 @@ Diagnostics_area::set_eof_status(THD *th
   if (is_error() || is_disabled())
     return;
 
-  m_server_status= thd->server_status;
   /*
     If inside a stored procedure, do not return the total
     number of warnings, since they are not available to the client

=== modified file 'sql/sql_error.h'
--- a/sql/sql_error.h	2010-07-30 15:28:36 +0000
+++ b/sql/sql_error.h	2010-10-19 18:59:12 +0000
@@ -79,12 +79,6 @@ public:
   const char* get_sqlstate() const
   { DBUG_ASSERT(m_status == DA_ERROR); return m_sqlstate; }
 
-  uint server_status() const
-  {
-    DBUG_ASSERT(m_status == DA_OK || m_status == DA_EOF);
-    return m_server_status;
-  }
-
   ulonglong affected_rows() const
   { DBUG_ASSERT(m_status == DA_OK); return m_affected_rows; }
 
@@ -111,15 +105,6 @@ private:
   char m_sqlstate[SQLSTATE_LENGTH+1];
 
   /**
-    Copied from thd->server_status when the diagnostics area is assigned.
-    We need this member as some places in the code use the following pattern:
-    thd->server_status|= ...
-    my_eof(thd);
-    thd->server_status&= ~...
-    Assigned by OK, EOF or ERROR.
-  */
-  uint m_server_status;
-  /**
     The number of rows affected by the last statement. This is
     semantically close to thd->row_count_func, but has a different
     life cycle. thd->row_count_func stores the value returned by

=== modified file 'sql/sql_parse.cc'
--- a/sql/sql_parse.cc	2010-10-07 16:01:17 +0000
+++ b/sql/sql_parse.cc	2010-10-19 18:59:12 +0000
@@ -1435,8 +1435,7 @@ void log_slow_statement(THD *thd)
     ulonglong end_utime_of_query= thd->current_utime();
     thd_proc_info(thd, "logging slow query");
 
-    if (((end_utime_of_query - thd->utime_after_lock) >
-         thd->variables.long_query_time ||
+    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 &&
@@ -5503,6 +5502,8 @@ void mysql_parse(THD *thd, char *rawbuf,
     thd->end_statement();
     thd->cleanup_after_query();
     DBUG_ASSERT(thd->change_list.is_empty());
+    /* Finalize server status flags after executing a statement. */
+    thd->update_server_status();
   }
 
   DBUG_VOID_RETURN;

=== modified file 'tests/mysql_client_test.c'
--- a/tests/mysql_client_test.c	2010-10-04 12:42:16 +0000
+++ b/tests/mysql_client_test.c	2010-10-19 18:59:12 +0000
@@ -19061,7 +19061,7 @@ static void test_bug49972()
   my_bool is_null;
 
   DBUG_ENTER("test_bug49972");
-  myheader("test_49972");
+  myheader("test_bug49972");
 
   rc= mysql_query(mysql, "DROP FUNCTION IF EXISTS f1");
   myquery(rc);
@@ -19148,6 +19148,42 @@ static void test_bug49972()
   DBUG_VOID_RETURN;
 }
 
+
+/**
+  Bug#57058 SERVER_QUERY_WAS_SLOW not wired up.
+*/
+
+static void test_bug57058()
+{
+  MYSQL_RES *res;
+  int rc;
+
+  DBUG_ENTER("test_bug57058");
+  myheader("test_bug57058");
+
+  rc= mysql_query(mysql, "set @@session.long_query_time=0.1");
+  myquery(rc);
+
+  DBUG_ASSERT(!(mysql->server_status & SERVER_QUERY_WAS_SLOW));
+
+  rc= mysql_query(mysql, "select sleep(1)");
+  myquery(rc);
+
+  /*
+    Important: the flag is sent in the last EOF packet of
+    the query, the one which ends the result. Read the
+    result to see the "slow" status.
+  */
+  res= mysql_store_result(mysql);
+
+  DBUG_ASSERT(mysql->server_status & SERVER_QUERY_WAS_SLOW);
+
+  mysql_free_result(res);
+
+  rc= mysql_query(mysql, "set @@session.long_query_time=default");
+
+  DBUG_VOID_RETURN;
+}
 /*
   Read and parse arguments and MySQL options from my.cnf
 */
@@ -19481,6 +19517,7 @@ static struct my_tests_st my_tests[]= {
   { "test_bug42373", test_bug42373 },
   { "test_bug54041", test_bug54041 },
   { "test_bug47485", test_bug47485 },
+  { "test_bug57058", test_bug57058 },
   { 0, 0 }
 };
 


Attachment: [text/bzr-bundle] bzr/kostja@sun.com-20101019185912-23oea5xl3sc8uix7.bundle
Thread
bzr commit into mysql-5.5-runtime branch (kostja:3167) Bug#57058Konstantin Osipov19 Oct
  • Re: bzr commit into mysql-5.5-runtime branch (kostja:3167) Bug#57058Davi Arnaut21 Oct