Commit 78fa2e4d authored by Konstantin Osipov's avatar Konstantin Osipov

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:
  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.
parent f11b9a88
...@@ -255,7 +255,11 @@ enum enum_server_command ...@@ -255,7 +255,11 @@ enum enum_server_command
#define SERVER_STATUS_CLEAR_SET (SERVER_QUERY_NO_GOOD_INDEX_USED| \ #define SERVER_STATUS_CLEAR_SET (SERVER_QUERY_NO_GOOD_INDEX_USED| \
SERVER_QUERY_NO_INDEX_USED|\ SERVER_QUERY_NO_INDEX_USED|\
SERVER_MORE_RESULTS_EXISTS|\ 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 MYSQL_ERRMSG_SIZE 512
#define NET_READ_TIMEOUT 30 /* Timeout on read */ #define NET_READ_TIMEOUT 30 /* Timeout on read */
......
...@@ -505,11 +505,11 @@ void Protocol::end_statement() ...@@ -505,11 +505,11 @@ void Protocol::end_statement()
thd->stmt_da->get_sqlstate()); thd->stmt_da->get_sqlstate());
break; break;
case Diagnostics_area::DA_EOF: 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()); thd->stmt_da->statement_warn_count());
break; break;
case Diagnostics_area::DA_OK: 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->statement_warn_count(),
thd->stmt_da->affected_rows(), thd->stmt_da->affected_rows(),
thd->stmt_da->last_insert_id(), thd->stmt_da->last_insert_id(),
......
...@@ -3100,7 +3100,12 @@ sp_instr_stmt::execute(THD *thd, uint *nextp) ...@@ -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); res= m_lex_keeper.reset_lex_and_exec_core(thd, nextp, FALSE, this);
if (thd->stmt_da->is_eof()) if (thd->stmt_da->is_eof())
{
/* Finalize server status flags after executing a statement. */
thd->update_server_status();
thd->protocol->end_statement(); thd->protocol->end_statement();
}
query_cache_end_of_result(thd); query_cache_end_of_result(thd);
......
...@@ -2234,6 +2234,20 @@ class THD :public Statement, ...@@ -2234,6 +2234,20 @@ class THD :public Statement,
} }
void set_time_after_lock() { utime_after_lock= my_micro_time(); } void set_time_after_lock() { utime_after_lock= my_micro_time(); }
ulonglong current_utime() { return 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) inline ulonglong found_rows(void)
{ {
return limit_found_rows; return limit_found_rows;
......
...@@ -277,7 +277,6 @@ int Materialized_cursor::open(JOIN *join __attribute__((unused))) ...@@ -277,7 +277,6 @@ int Materialized_cursor::open(JOIN *join __attribute__((unused)))
rc= result->send_result_set_metadata(item_list, Protocol::SEND_NUM_ROWS); rc= result->send_result_set_metadata(item_list, Protocol::SEND_NUM_ROWS);
thd->server_status|= SERVER_STATUS_CURSOR_EXISTS; thd->server_status|= SERVER_STATUS_CURSOR_EXISTS;
result->send_eof(); result->send_eof();
thd->server_status&= ~SERVER_STATUS_CURSOR_EXISTS;
} }
return rc; return rc;
} }
...@@ -318,12 +317,10 @@ void Materialized_cursor::fetch(ulong num_rows) ...@@ -318,12 +317,10 @@ void Materialized_cursor::fetch(ulong num_rows)
case 0: case 0:
thd->server_status|= SERVER_STATUS_CURSOR_EXISTS; thd->server_status|= SERVER_STATUS_CURSOR_EXISTS;
result->send_eof(); result->send_eof();
thd->server_status&= ~SERVER_STATUS_CURSOR_EXISTS;
break; break;
case HA_ERR_END_OF_FILE: case HA_ERR_END_OF_FILE:
thd->server_status|= SERVER_STATUS_LAST_ROW_SENT; thd->server_status|= SERVER_STATUS_LAST_ROW_SENT;
result->send_eof(); result->send_eof();
thd->server_status&= ~SERVER_STATUS_LAST_ROW_SENT;
close(); close();
break; break;
default: default:
......
...@@ -866,7 +866,6 @@ bool mysql_rm_db(THD *thd,char *db,bool if_exists, bool silent) ...@@ -866,7 +866,6 @@ bool mysql_rm_db(THD *thd,char *db,bool if_exists, bool silent)
thd->clear_error(); thd->clear_error();
thd->server_status|= SERVER_STATUS_DB_DROPPED; thd->server_status|= SERVER_STATUS_DB_DROPPED;
my_ok(thd, (ulong) deleted); my_ok(thd, (ulong) deleted);
thd->server_status&= ~SERVER_STATUS_DB_DROPPED;
} }
else if (mysql_bin_log.is_open()) else if (mysql_bin_log.is_open())
{ {
......
...@@ -365,7 +365,6 @@ Diagnostics_area::set_ok_status(THD *thd, ulonglong affected_rows_arg, ...@@ -365,7 +365,6 @@ Diagnostics_area::set_ok_status(THD *thd, ulonglong affected_rows_arg,
if (is_error() || is_disabled()) if (is_error() || is_disabled())
return; return;
m_server_status= thd->server_status;
m_statement_warn_count= thd->warning_info->statement_warn_count(); m_statement_warn_count= thd->warning_info->statement_warn_count();
m_affected_rows= affected_rows_arg; m_affected_rows= affected_rows_arg;
m_last_insert_id= last_insert_id_arg; m_last_insert_id= last_insert_id_arg;
...@@ -395,7 +394,6 @@ Diagnostics_area::set_eof_status(THD *thd) ...@@ -395,7 +394,6 @@ Diagnostics_area::set_eof_status(THD *thd)
if (is_error() || is_disabled()) if (is_error() || is_disabled())
return; return;
m_server_status= thd->server_status;
/* /*
If inside a stored procedure, do not return the total If inside a stored procedure, do not return the total
number of warnings, since they are not available to the client number of warnings, since they are not available to the client
......
...@@ -79,12 +79,6 @@ class Diagnostics_area ...@@ -79,12 +79,6 @@ class Diagnostics_area
const char* get_sqlstate() const const char* get_sqlstate() const
{ DBUG_ASSERT(m_status == DA_ERROR); return m_sqlstate; } { 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 ulonglong affected_rows() const
{ DBUG_ASSERT(m_status == DA_OK); return m_affected_rows; } { DBUG_ASSERT(m_status == DA_OK); return m_affected_rows; }
...@@ -110,15 +104,6 @@ class Diagnostics_area ...@@ -110,15 +104,6 @@ class Diagnostics_area
char m_sqlstate[SQLSTATE_LENGTH+1]; 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 The number of rows affected by the last statement. This is
semantically close to thd->row_count_func, but has a different semantically close to thd->row_count_func, but has a different
......
...@@ -1438,8 +1438,7 @@ void log_slow_statement(THD *thd) ...@@ -1438,8 +1438,7 @@ void log_slow_statement(THD *thd)
ulonglong end_utime_of_query= thd->current_utime(); ulonglong end_utime_of_query= thd->current_utime();
thd_proc_info(thd, "logging slow query"); thd_proc_info(thd, "logging slow query");
if (((end_utime_of_query - thd->utime_after_lock) > if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
thd->variables.long_query_time ||
((thd->server_status & ((thd->server_status &
(SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) && (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
opt_log_queries_not_using_indexes && opt_log_queries_not_using_indexes &&
...@@ -5505,6 +5504,8 @@ void mysql_parse(THD *thd, char *rawbuf, uint length, ...@@ -5505,6 +5504,8 @@ void mysql_parse(THD *thd, char *rawbuf, uint length,
thd->end_statement(); thd->end_statement();
thd->cleanup_after_query(); thd->cleanup_after_query();
DBUG_ASSERT(thd->change_list.is_empty()); DBUG_ASSERT(thd->change_list.is_empty());
/* Finalize server status flags after executing a statement. */
thd->update_server_status();
} }
DBUG_VOID_RETURN; DBUG_VOID_RETURN;
......
...@@ -19061,7 +19061,7 @@ static void test_bug49972() ...@@ -19061,7 +19061,7 @@ static void test_bug49972()
my_bool is_null; my_bool is_null;
DBUG_ENTER("test_bug49972"); DBUG_ENTER("test_bug49972");
myheader("test_49972"); myheader("test_bug49972");
rc= mysql_query(mysql, "DROP FUNCTION IF EXISTS f1"); rc= mysql_query(mysql, "DROP FUNCTION IF EXISTS f1");
myquery(rc); myquery(rc);
...@@ -19148,6 +19148,45 @@ static void test_bug49972() ...@@ -19148,6 +19148,45 @@ static void test_bug49972()
DBUG_VOID_RETURN; 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 Read and parse arguments and MySQL options from my.cnf
*/ */
...@@ -19481,6 +19520,7 @@ static struct my_tests_st my_tests[]= { ...@@ -19481,6 +19520,7 @@ static struct my_tests_st my_tests[]= {
{ "test_bug42373", test_bug42373 }, { "test_bug42373", test_bug42373 },
{ "test_bug54041", test_bug54041 }, { "test_bug54041", test_bug54041 },
{ "test_bug47485", test_bug47485 }, { "test_bug47485", test_bug47485 },
{ "test_bug57058", test_bug57058 },
{ 0, 0 } { 0, 0 }
}; };
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment