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.
Implement review comments.

include/mysql_com.h

@@ -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 */

sql/protocol.cc

@@ -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(),

sql/sp_head.cc

@@ -3100,7 +3100,12 @@ sp_instr_stmt::execute(THD *thd, uint *nextp)
       res= m_lex_keeper.reset_lex_and_exec_core(thd, nextp, FALSE, this);
 
       if (thd->stmt_da->is_eof())
+      {
+        /* Finalize server status flags after executing a statement. */
+        thd->update_server_status();
+
         thd->protocol->end_statement();
+      }
 
       query_cache_end_of_result(thd);
 

sql/sql_class.h

@@ -2234,6 +2234,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;

sql/sql_cursor.cc

@@ -277,7 +277,6 @@ int Materialized_cursor::open(JOIN *join __attribute__((unused)))
     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 num_rows)
   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:

sql/sql_db.cc

@@ -866,7 +866,6 @@ bool mysql_rm_db(THD *thd,char *db,bool if_exists, bool silent)
     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())
   {

sql/sql_error.cc

@@ -365,7 +365,6 @@ Diagnostics_area::set_ok_status(THD *thd, ulonglong affected_rows_arg,
   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 *thd)
   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

sql/sql_error.h

@@ -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; }
 
@@ -110,15 +104,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

sql/sql_parse.cc

@@ -1438,8 +1438,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 &&
@@ -5505,6 +5504,8 @@ void mysql_parse(THD *thd, char *rawbuf, uint length,
     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;

tests/mysql_client_test.c

@@ -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,45 @@ 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);
+
+  DIE_UNLESS(!(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);
+
+  DIE_UNLESS(mysql->server_status & SERVER_QUERY_WAS_SLOW);
+
+  mysql_free_result(res);
+
+  rc= mysql_query(mysql, "set @@session.long_query_time=default");
+  myquery(rc);
+
+  DBUG_VOID_RETURN;
+}
+
+
 /*
   Read and parse arguments and MySQL options from my.cnf
 */
@@ -19481,6 +19520,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 }
 };