# should be done or reviewed by the maintainer!
--- a/include/mysql/plugin_audit.h.pp
+++ b/include/mysql/plugin_audit.h.pp
-@@ -185,6 +185,16 @@
+@@ -186,6 +186,16 @@
char *thd_security_context(void* thd, char *buffer, unsigned int length,
unsigned int max_query_len);
void thd_inc_row_count(void* thd);
unsigned long thd_get_thread_id(const void* thd);
--- a/include/mysql/plugin_auth.h.pp
+++ b/include/mysql/plugin_auth.h.pp
-@@ -185,6 +185,16 @@
+@@ -186,6 +186,16 @@
char *thd_security_context(void* thd, char *buffer, unsigned int length,
unsigned int max_query_len);
void thd_inc_row_count(void* thd);
unsigned long thd_get_thread_id(const void* thd);
--- a/include/mysql/plugin_ftparser.h.pp
+++ b/include/mysql/plugin_ftparser.h.pp
-@@ -138,6 +138,16 @@
+@@ -139,6 +139,16 @@
char *thd_security_context(void* thd, char *buffer, unsigned int length,
unsigned int max_query_len);
void thd_inc_row_count(void* thd);
unsigned long thd_get_thread_id(const void* thd);
--- a/include/mysql/plugin.h
+++ b/include/mysql/plugin.h
-@@ -536,6 +536,17 @@
+@@ -545,6 +545,17 @@
/* Increments the row counter, see THD::row_count */
void thd_inc_row_count(MYSQL_THD thd);
thd->client_capabilities|= CLIENT_MULTI_RESULTS;
mysql_mutex_lock(&LOCK_thread_count);
thd->thread_id= thd->variables.pseudo_thread_id= thread_id++;
-+ thd->write_to_slow_log = TRUE;
++ thd->write_to_slow_log= true;
mysql_mutex_unlock(&LOCK_thread_count);
/*
--- a/sql/filesort.cc
+++ b/sql/filesort.cc
-@@ -195,6 +195,7 @@
+@@ -193,6 +193,7 @@
{
status_var_increment(thd->status_var.filesort_scan_count);
}
#ifdef CAN_TRUST_RANGE
if (select && select->quick && select->quick->records > 0L)
{
-@@ -260,6 +261,7 @@
- }
- else
- {
+@@ -261,6 +262,7 @@
+ /* filesort cannot handle zero-length records during merge. */
+ DBUG_ASSERT(param.sort_length != 0);
+
+ thd->query_plan_flags|= QPLAN_FILESORT_DISK;
if (table_sort.buffpek && table_sort.buffpek_len < maxbuffer)
{
my_free(table_sort.buffpek);
-@@ -1219,6 +1221,7 @@
+@@ -1209,6 +1211,7 @@
DBUG_ENTER("merge_buffers");
status_var_increment(current_thd->status_var.filesort_merge_passes);
user_host, user_host_len,
query_utime, lock_utime, is_command,
sql_text, sql_text_len);
-@@ -1216,7 +1218,7 @@
+@@ -1200,8 +1202,6 @@
+
+ if (*slow_log_handler_list)
+ {
+- time_t current_time;
+-
+ /* do not log slow queries from replication threads */
+ if (thd->slave_thread && !opt_log_slow_slave_statements)
+ return 0;
+@@ -1216,16 +1216,29 @@
/* fill in user_host value: the format is "%s[%s] @ %s [%s]" */
user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
sctx->priv_user ? sctx->priv_user : "", "[",
sctx->host ? sctx->host : "", " [",
sctx->ip ? sctx->ip : "", "]", NullS) -
user_host_buff);
-@@ -1224,8 +1226,22 @@
- current_time= my_time_possible_from_micro(current_utime);
+
+- current_time= my_time_possible_from_micro(current_utime);
if (thd->start_utime)
{
- query_utime= (current_utime - thd->start_utime);
}
else
{
-@@ -1239,8 +1255,20 @@
- query_length= command_name[thd->command].length;
+@@ -1240,7 +1253,7 @@
}
-+ if (!query_length)
-+ {
-+ thd->sent_row_count= thd->examined_row_count= 0;
-+ thd->sent_row_count= 0;
-+ thd->bytes_sent_old= thd->status_var.bytes_sent;
-+ thd->tmp_tables_used= thd->tmp_tables_disk_used= 0;
-+ thd->tmp_tables_size= 0;
-+ thd->innodb_was_used= FALSE;
-+ thd->query_plan_flags= QPLAN_NONE;
-+ thd->query_plan_fsort_passes= 0;
-+ }
-+
for (current_handler= slow_log_handler_list; *current_handler ;)
- error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,
+ error= (*current_handler++)->log_slow(thd, current_utime, thd->start_time,
user_host_buff, user_host_len,
query_utime, lock_utime, is_command,
query, query_length) || error;
-@@ -2656,12 +2684,13 @@
+@@ -2656,12 +2669,13 @@
TRUE - error occured
*/
bool error= 0;
DBUG_ENTER("MYSQL_QUERY_LOG::write");
-@@ -2683,17 +2712,28 @@
+@@ -2683,17 +2697,28 @@
if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
{
/* Note that my_b_write() assumes it knows the length for this */
if (my_b_write(&log_file, (uchar*) buff, buff_len))
-@@ -2711,12 +2751,69 @@
+@@ -2710,13 +2735,71 @@
+ /* For slow query log */
sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0);
++ DBUG_PRINT("info", ("Last_errno: %u", thd->last_errno));
if (my_b_printf(&log_file,
- "# Query_time: %s Lock_time: %s"
- " Rows_sent: %lu Rows_examined: %lu\n",
const char *user_host, uint user_host_len,
ulonglong query_utime, ulonglong lock_utime, bool is_command,
const char *sql_text, uint sql_text_len);
-@@ -515,7 +515,7 @@
+@@ -517,7 +517,7 @@
virtual bool init()= 0;
virtual void cleanup()= 0;
time_t query_start_arg, const char *user_host,
uint user_host_len, ulonglong query_utime,
ulonglong lock_utime, bool is_command,
-@@ -544,7 +544,7 @@
+@@ -546,7 +546,7 @@
virtual bool init();
virtual void cleanup();
time_t query_start_arg, const char *user_host,
uint user_host_len, ulonglong query_utime,
ulonglong lock_utime, bool is_command,
-@@ -576,7 +576,7 @@
+@@ -578,7 +578,7 @@
virtual bool init();
virtual void cleanup();
ulonglong lock_utime, bool is_command,
--- a/sql/mysqld.cc
+++ b/sql/mysqld.cc
-@@ -421,6 +421,10 @@
+@@ -421,6 +421,11 @@
char* opt_secure_file_priv;
my_bool opt_log_slow_admin_statements= 0;
my_bool opt_log_slow_slave_statements= 0;
+my_bool opt_slow_query_log_timestamp_always= 0;
+ulonglong opt_slow_query_log_use_global_control= 0;
+ulong opt_slow_query_log_timestamp_precision= 0;
++ulong opt_slow_query_log_rate_type= 0;
my_bool lower_case_file_system= 0;
my_bool opt_large_pages= 0;
my_bool opt_super_large_pages= 0;
-@@ -5896,10 +5900,10 @@
- "Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to "
- "the slow log if it is open.", &opt_log_slow_admin_statements,
- &opt_log_slow_admin_statements, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
+@@ -5892,14 +5897,10 @@
+ "Don't log extra information to update and slow-query logs.",
+ &opt_short_log_format, &opt_short_log_format,
+ 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
+- {"log-slow-admin-statements", 0,
+- "Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to "
+- "the slow log if it is open.", &opt_log_slow_admin_statements,
+- &opt_log_slow_admin_statements, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
- {"log-slow-slave-statements", 0,
+ /*{"log-slow-slave-statements", 0,
"Log slow statements executed by slave thread to the slow log if it is open.",
{"log-slow-queries", OPT_SLOW_QUERY_LOG,
"Log slow queries to a table or log file. Defaults logging to table "
"mysql.slow_log or hostname-slow.log if --log-output=file is used. "
-@@ -7288,6 +7292,10 @@
+@@ -7288,6 +7289,10 @@
C_MODE_END
/**
Get server options from the command line,
and perform related server initializations.
-@@ -7437,6 +7445,8 @@
+@@ -7437,6 +7442,8 @@
global_system_variables.long_query_time= (ulonglong)
(global_system_variables.long_query_time_double * 1e6);
--- a/sql/mysqld.h
+++ b/sql/mysqld.h
-@@ -116,6 +116,10 @@
+@@ -116,6 +116,11 @@
extern char* opt_secure_backup_file_priv;
extern size_t opt_secure_backup_file_priv_len;
extern my_bool opt_log_slow_admin_statements, opt_log_slow_slave_statements;
+extern my_bool opt_slow_query_log_timestamp_always;
+extern ulonglong opt_slow_query_log_use_global_control;
+extern ulong opt_slow_query_log_timestamp_precision;
++extern ulong opt_slow_query_log_rate_type;
extern my_bool sp_automatic_privileges, opt_noacl;
extern my_bool opt_old_style_user_limits, trust_function_creators;
extern uint opt_crash_binlog_innodb;
mysql_mutex_lock(&LOCK_thread_count);
--- a/sql/sp_head.cc
+++ b/sql/sp_head.cc
-@@ -2152,7 +2152,7 @@
+@@ -2164,7 +2164,7 @@
DBUG_PRINT("info",(" %.*s: eval args done", (int) m_name.length,
m_name.str));
}
save_enable_slow_log= true;
--- a/sql/sql_cache.cc
+++ b/sql/sql_cache.cc
-@@ -1756,6 +1756,7 @@
+@@ -1780,6 +1780,7 @@
response, we can't handle it anyway.
*/
(void) trans_commit_stmt(thd);
if (!thd->stmt_da->is_set())
thd->stmt_da->disable_status();
-@@ -1766,6 +1767,7 @@
+@@ -1790,6 +1791,7 @@
err_unlock:
unlock();
err:
+extern "C"
+void increment_thd_innodb_stats(THD* thd,
-+ unsigned long long trx_id,
-+ long io_reads,
-+ long long io_read,
-+ long io_reads_wait_timer,
-+ long lock_que_wait_timer,
-+ long que_wait_timer,
-+ long page_access)
++ unsigned long long trx_id,
++ long io_reads,
++ long long io_read,
++ long io_reads_wait_timer,
++ long lock_que_wait_timer,
++ long que_wait_timer,
++ long page_access)
+{
-+ thd->innodb_was_used = TRUE;
-+ thd->innodb_trx_id = trx_id;
-+ thd->innodb_io_reads += io_reads;
-+ thd->innodb_io_read += io_read;
-+ thd->innodb_io_reads_wait_timer += io_reads_wait_timer;
-+ thd->innodb_lock_que_wait_timer += lock_que_wait_timer;
-+ thd->innodb_innodb_que_wait_timer += que_wait_timer;
-+ thd->innodb_page_access += page_access;
++ thd->innodb_was_used= TRUE;
++ thd->innodb_trx_id= trx_id;
++ thd->innodb_io_reads+= io_reads;
++ thd->innodb_io_read+= io_read;
++ thd->innodb_io_reads_wait_timer+= io_reads_wait_timer;
++ thd->innodb_lock_que_wait_timer+= lock_que_wait_timer;
++ thd->innodb_innodb_que_wait_timer+= que_wait_timer;
++ thd->innodb_page_access+= page_access;
+}
+
+extern "C"
/**
Dumps a text description of a thread, its security context
-@@ -912,6 +943,7 @@
- *cond_hdl= NULL;
- return FALSE;
- }
+@@ -942,6 +973,8 @@
+ const char* msg,
+ MYSQL_ERROR ** cond_hdl)
+ {
+ last_errno= sql_errno;
++
+ if (!m_internal_handler)
+ {
+ *cond_hdl= NULL;
+@@ -1236,6 +1269,8 @@
+ /* Initialize the Debug Sync Facility. See debug_sync.cc. */
+ debug_sync_init_thread(this);
+ #endif /* defined(ENABLED_DEBUG_SYNC) */
++
++ clear_slow_extended();
+ }
+
- for (Internal_error_handler *error_handler= m_internal_handler;
- error_handler;
-@@ -3656,6 +3688,12 @@
+@@ -3687,8 +3722,6 @@
+ backup->in_sub_stmt= in_sub_stmt;
+ backup->enable_slow_log= enable_slow_log;
+ backup->limit_found_rows= limit_found_rows;
+- backup->examined_row_count= examined_row_count;
+- backup->sent_row_count= sent_row_count;
+ backup->cuted_fields= cuted_fields;
+ backup->client_capabilities= client_capabilities;
+ backup->savepoints= transaction.savepoints;
+@@ -3696,6 +3729,7 @@
first_successful_insert_id_in_prev_stmt;
backup->first_successful_insert_id_in_cur_stmt=
first_successful_insert_id_in_cur_stmt;
-+ backup->innodb_io_reads= innodb_io_reads;
-+ backup->innodb_io_read= innodb_io_read;
-+ backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer;
-+ backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer;
-+ backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
-+ backup->innodb_page_access= innodb_page_access;
++ reset_sub_statement_state_slow_extended(backup);
if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) &&
!is_current_stmt_binlog_format_row())
-@@ -3676,6 +3714,14 @@
+@@ -3711,13 +3745,74 @@
+ /* Disable result sets */
+ client_capabilities &= ~CLIENT_MULTI_RESULTS;
+ in_sub_stmt|= new_state;
+- examined_row_count= 0;
+- sent_row_count= 0;
cuted_fields= 0;
transaction.savepoints= 0;
first_successful_insert_id_in_cur_stmt= 0;
-+ last_errno= 0;
-+ innodb_trx_id= 0;
-+ innodb_io_reads= 0;
-+ innodb_io_read= 0;
-+ innodb_io_reads_wait_timer= 0;
-+ innodb_lock_que_wait_timer= 0;
-+ innodb_innodb_que_wait_timer= 0;
-+ innodb_page_access= 0;
}
++void THD::clear_slow_extended()
++{
++ DBUG_ENTER("THD::clear_slow_extended");
++ sent_row_count= 0;
++ examined_row_count= 0;
++ bytes_sent_old= status_var.bytes_sent;
++ tmp_tables_used= 0;
++ tmp_tables_disk_used= 0;
++ tmp_tables_size= 0;
++ innodb_was_used= FALSE;
++ innodb_trx_id= 0;
++ innodb_io_reads= 0;
++ innodb_io_read= 0;
++ innodb_io_reads_wait_timer= 0;
++ innodb_lock_que_wait_timer= 0;
++ innodb_innodb_que_wait_timer= 0;
++ innodb_page_access= 0;
++ query_plan_flags= QPLAN_NONE;
++ query_plan_fsort_passes= 0;
++ last_errno= 0;
++ DBUG_VOID_RETURN;
++}
++
++void THD::reset_sub_statement_state_slow_extended(Sub_statement_state *backup)
++{
++ DBUG_ENTER("THD::reset_sub_statement_state_slow_extended");
++ backup->sent_row_count= sent_row_count;
++ backup->examined_row_count= examined_row_count;
++ backup->tmp_tables_used= tmp_tables_used;
++ backup->tmp_tables_disk_used= tmp_tables_disk_used;
++ backup->tmp_tables_size= tmp_tables_size;
++ backup->innodb_was_used= innodb_was_used;
++ backup->innodb_io_reads= innodb_io_reads;
++ backup->innodb_io_read= innodb_io_read;
++ backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer;
++ backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer;
++ backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
++ backup->innodb_page_access= innodb_page_access;
++ backup->query_plan_flags= query_plan_flags;
++ backup->query_plan_fsort_passes= query_plan_fsort_passes;
++ clear_slow_extended();
++ DBUG_VOID_RETURN;
++}
++
++void THD::restore_sub_statement_state_slow_extended(const Sub_statement_state *backup)
++{
++ DBUG_ENTER("THD::restore_sub_statement_state_slow_extended");
++ sent_row_count= backup->sent_row_count;
++ examined_row_count+= backup->examined_row_count;
++ tmp_tables_used+= backup->tmp_tables_used;
++ tmp_tables_disk_used+= backup->tmp_tables_disk_used;
++ tmp_tables_size+= backup->tmp_tables_size;
++ innodb_was_used= (innodb_was_used || backup->innodb_was_used);
++ innodb_io_reads+= backup->innodb_io_reads;
++ innodb_io_read+= backup->innodb_io_read;
++ innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer;
++ innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer;
++ innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
++ innodb_page_access+= backup->innodb_page_access;
++ query_plan_flags|= backup->query_plan_flags;
++ query_plan_fsort_passes+= backup->query_plan_fsort_passes;
++ DBUG_VOID_RETURN;
++}
-@@ -3738,6 +3784,12 @@
+ void THD::restore_sub_statement_state(Sub_statement_state *backup)
+ {
+@@ -3758,7 +3853,6 @@
+ first_successful_insert_id_in_cur_stmt=
+ backup->first_successful_insert_id_in_cur_stmt;
+ limit_found_rows= backup->limit_found_rows;
+- sent_row_count= backup->sent_row_count;
+ client_capabilities= backup->client_capabilities;
+ /*
+ If we've left sub-statement mode, reset the fatal error flag.
+@@ -3776,8 +3870,8 @@
+ The following is added to the old values as we are interested in the
+ total complexity of the query
*/
- examined_row_count+= backup->examined_row_count;
+- examined_row_count+= backup->examined_row_count;
cuted_fields+= backup->cuted_fields;
-+ innodb_io_reads+= backup->innodb_io_reads;
-+ innodb_io_read+= backup->innodb_io_read;
-+ innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer;
-+ innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer;
-+ innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
-+ innodb_page_access+= backup->innodb_page_access;
++ restore_sub_statement_state_slow_extended(backup);
DBUG_VOID_RETURN;
}
+@@ -3802,7 +3896,7 @@
+ {
+ mysql_mutex_lock(&LOCK_thd_data);
+ set_query_inner(query_arg, query_length_arg, cs);
+- query_id= new_query_id;
++ do_set_query_id(new_query_id);
+ mysql_mutex_unlock(&LOCK_thd_data);
+ }
+
+@@ -3811,9 +3905,25 @@
+ void THD::set_query_id(query_id_t new_query_id)
+ {
+ mysql_mutex_lock(&LOCK_thd_data);
+- query_id= new_query_id;
++ do_set_query_id(new_query_id);
+ mysql_mutex_unlock(&LOCK_thd_data);
+ }
++void THD::do_set_query_id(query_id_t new_query_id)
++{
++#ifndef DBUG_OFF
++ if (variables.query_exec_id != 0 &&
++ lex->sql_command != SQLCOM_SET_OPTION)
++ {
++ new_query_id= variables.query_exec_id;
++ }
++#endif /* DBUG_OFF */
++ query_id= new_query_id;
++ if (opt_slow_query_log_rate_type == SLOG_RT_QUERY)
++ {
++ const ulong& limit= variables.log_slow_rate_limit;
++ write_to_slow_log= limit == 0 || (query_id % limit) == 0;
++ }
++}
+
+ /** Assign a new value to thd->mysys_var. */
+ void THD::set_mysys_var(struct st_my_thread_var *new_mysys_var)
--- a/sql/sql_class.h
+++ b/sql/sql_class.h
-@@ -60,6 +60,33 @@
+@@ -60,6 +60,36 @@
enum enum_duplicates { DUP_ERROR, DUP_REPLACE, DUP_UPDATE };
enum enum_delay_key_write { DELAY_KEY_WRITE_NONE, DELAY_KEY_WRITE_ON,
DELAY_KEY_WRITE_ALL };
+enum enum_slow_query_log_timestamp_precision {
+ SLOG_SECOND, SLOG_MICROSECOND
+};
++enum enum_slow_query_log_rate_type {
++ SLOG_RT_SESSION, SLOG_RT_QUERY
++};
+#define QPLAN_NONE 0
+#define QPLAN_QC 1 << 0
+#define QPLAN_QC_NO 1 << 1
enum enum_slave_exec_mode { SLAVE_EXEC_MODE_STRICT,
SLAVE_EXEC_MODE_IDEMPOTENT,
SLAVE_EXEC_MODE_LAST_BIT};
-@@ -508,6 +535,21 @@
+@@ -508,6 +538,22 @@
my_bool sysdate_is_now;
+#ifndef DBUG_OFF
+ ulonglong query_exec_time;
+ double query_exec_time_double;
++ ulong query_exec_id;
+#endif
+ ulong log_slow_rate_limit;
+ ulonglong log_slow_filter;
double long_query_time_double;
} SV;
-@@ -1140,6 +1182,14 @@
+@@ -1140,6 +1186,24 @@
uint in_sub_stmt;
bool enable_slow_log;
bool last_insert_id_used;
+
++ /*** Following variables used in slow_extended.patch ***/
++ ulong tmp_tables_used;
++ ulong tmp_tables_disk_used;
++ ulonglong tmp_tables_size;
++
++ bool innodb_was_used;
+ ulong innodb_io_reads;
+ ulonglong innodb_io_read;
+ ulong innodb_io_reads_wait_timer;
+ ulong innodb_lock_que_wait_timer;
+ ulong innodb_innodb_que_wait_timer;
+ ulong innodb_page_access;
++
++ ulong query_plan_flags;
++ ulong query_plan_fsort_passes;
++ /*** The variables above used in slow_extended.patch ***/
+
SAVEPOINT *savepoints;
enum enum_check_fields count_cuted_fields;
};
-@@ -1588,6 +1638,26 @@
+@@ -1588,6 +1652,71 @@
thr_lock_type update_lock_default;
Delayed_insert *di;
++ /*** Following variables used in slow_extended.patch ***/
++ /*
++ Variable write_to_slow_log:
++ 1) initialized in
++ * sql_connect.cc (log_slow_rate_limit support)
++ * slave.cc (log_slow_slave_statements support)
++ 2) The variable is initialized on the thread startup and remains
++ constant afterwards. This will change when
++ LP #712396 ("log_slow_slave_statements not work on replication
++ threads without RESTART") is implemented.
++ 3) An implementation of LP #688646 ("Make query sampling possible by query") should use it.
++ */
+ bool write_to_slow_log;
-+
++ /*
++ Variable bytes_send_old saves value of thd->status_var.bytes_sent
++ before query execution.
++ */
+ ulonglong bytes_sent_old;
++ /*
++ Variables tmp_tables_*** collect statistics about usage of temporary tables
++ */
+ ulong tmp_tables_used;
+ ulong tmp_tables_disk_used;
+ ulonglong tmp_tables_size;
++ /*
++ Variable innodb_was_used shows used or not InnoDB engine in current query.
++ */
+ bool innodb_was_used;
++ /*
++ Following Variables innodb_*** (is |should be) different from
++ default values only if (innodb_was_used==TRUE)
++ */
+ ulonglong innodb_trx_id;
+ ulong innodb_io_reads;
+ ulonglong innodb_io_read;
+ ulong innodb_innodb_que_wait_timer;
+ ulong innodb_page_access;
+
++ /*
++ Variable query_plan_flags collects information about query plan entites
++ used on query execution.
++ */
+ ulong query_plan_flags;
++ /*
++ Variable query_plan_fsort_passes collects information about file sort passes
++ acquired during query execution.
++ */
+ ulong query_plan_fsort_passes;
-+
++ /*
++ Query can generate several errors/warnings during execution
++ (see THD::handle_condition comment in sql_class.h)
++ Variable last_errno contains the last error/warning acquired during
++ query execution.
++ */
+ uint last_errno;
++ /*** The variables above used in slow_extended.patch ***/
++
++ /*** Following methods used in slow_extended.patch ***/
++ void clear_slow_extended();
++ void reset_sub_statement_state_slow_extended(Sub_statement_state *backup);
++ void restore_sub_statement_state_slow_extended(const Sub_statement_state *backup);
++ /*** The methods above used in slow_extended.patch ***/
+
/* <> 0 if we are inside of trigger or stored function. */
uint in_sub_stmt;
+@@ -2784,6 +2913,9 @@
+ void set_query_and_id(char *query_arg, uint32 query_length_arg,
+ CHARSET_INFO *cs, query_id_t new_query_id);
+ void set_query_id(query_id_t new_query_id);
++private:
++ void do_set_query_id(query_id_t new_query_id);
++public:
+ void set_open_tables(TABLE *open_tables_arg)
+ {
+ mysql_mutex_lock(&LOCK_thd_data);
--- a/sql/sql_connect.cc
+++ b/sql/sql_connect.cc
-@@ -721,6 +721,15 @@
+@@ -721,6 +721,14 @@
MYSQL_CONNECTION_START(thd->thread_id, &thd->security_ctx->priv_user[0],
(char *) thd->security_ctx->host_or_ip);
-+ /*
-+ If rate limiting of slow log writes is enabled, decide whether to log this
-+ new thread's queries or not. Uses extremely simple algorithm. :)
-+ */
-+ thd->write_to_slow_log= FALSE;
-+ if (thd->variables.log_slow_rate_limit <= 1 ||
-+ (thd->thread_id % thd->variables.log_slow_rate_limit) == 0)
-+ thd->write_to_slow_log= TRUE;
++ /*
++ If rate limiting of slow log writes is enabled, decide whether to log this
++ new thread's queries or not. Uses extremely simple algorithm. :)
++ */
++ const ulong& limit= thd->variables.log_slow_rate_limit;
++ thd->write_to_slow_log= opt_slow_query_log_rate_type == SLOG_RT_SESSION &&
++ (limit == 0 || (thd->thread_id % limit) == 0);
+
prepare_new_connection_state(thd);
return FALSE;
const char *any_db="*any*"; // Special symbol for check_access
-@@ -1430,6 +1431,60 @@
+@@ -890,6 +891,7 @@
+ the slow log only if opt_log_slow_admin_statements is set.
+ */
+ thd->enable_slow_log= TRUE;
++ thd->clear_slow_extended();
+ thd->lex->sql_command= SQLCOM_END; /* to avoid confusing VIEW detectors */
+ thd->set_time();
+ if (!thd->is_valid_time())
+@@ -1440,6 +1442,60 @@
DBUG_RETURN(error);
}
void log_slow_statement(THD *thd)
{
-@@ -1443,13 +1498,48 @@
+@@ -1453,13 +1509,47 @@
if (unlikely(thd->in_sub_stmt))
DBUG_VOID_RETURN; // Don't set time for sub stmt
+ &g.min_examined_row_limit);
+
+ /* Do not log this thread's queries due to rate limiting. */
-+ if (thd->write_to_slow_log != TRUE
-+ && (thd->variables.long_query_time >= 1000000
-+ || (ulong) query_exec_time < 1000000))
++ if (!thd->write_to_slow_log && (thd->variables.long_query_time >= 1000000
++ || (ulong) query_exec_time < 1000000))
+ DBUG_VOID_RETURN;
+
+
thd_proc_info(thd, "logging slow query");
if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
-@@ -1879,6 +1969,9 @@
- context.resolve_in_table_list_only(select_lex->
- table_list.first);
-
-+ /* Reset the counter at all cases for the extended slow query log */
-+ thd->sent_row_count= 0;
-+
- /*
- Reset warning count for each query that uses tables
- A better approach would be to reset this for any commands
-@@ -5297,6 +5390,21 @@
+@@ -5368,7 +5459,8 @@
+ thd->stmt_da->reset_diagnostics_area();
+ thd->warning_info->reset_for_next_command();
thd->rand_used= 0;
- thd->sent_row_count= thd->examined_row_count= 0;
-
-+ thd->bytes_sent_old= thd->status_var.bytes_sent;
-+ thd->tmp_tables_used= thd->tmp_tables_disk_used= 0;
-+ thd->tmp_tables_size= 0;
-+ thd->innodb_was_used= FALSE;
-+ thd->innodb_trx_id= 0;
-+ thd->innodb_io_reads= 0;
-+ thd->innodb_io_read= 0;
-+ thd->innodb_io_reads_wait_timer= 0;
-+ thd->innodb_lock_que_wait_timer= 0;
-+ thd->innodb_innodb_que_wait_timer= 0;
-+ thd->innodb_page_access= 0;
-+ thd->query_plan_flags= QPLAN_NONE;
-+ thd->query_plan_fsort_passes= 0;
-+ thd->last_errno= 0;
+- thd->sent_row_count= thd->examined_row_count= 0;
+
++ thd->clear_slow_extended();
+
thd->reset_current_stmt_binlog_format_row();
thd->binlog_unsafe_warning_flags= 0;
-
--- a/sql/sql_select.cc
+++ b/sql/sql_select.cc
-@@ -6902,7 +6902,10 @@
+@@ -6912,7 +6912,10 @@
{
join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
if (statistics)
}
}
else
-@@ -6916,7 +6919,10 @@
+@@ -6926,7 +6929,10 @@
{
join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
if (statistics)
}
}
if (!table->no_keyread)
-@@ -10264,6 +10270,7 @@
+@@ -10274,6 +10280,7 @@
(ulong) rows_limit,test(group)));
status_var_increment(thd->status_var.created_tmp_tables);
if (use_temp_pool && !(test_flags & TEST_KEEP_TMP_TABLES))
temp_pool_slot = bitmap_lock_set_next(&temp_pool);
-@@ -11162,6 +11169,7 @@
+@@ -11175,6 +11182,7 @@
goto err;
}
status_var_increment(table->in_use->status_var.created_tmp_disk_tables);
share->db_record_offset= 1;
DBUG_RETURN(0);
err:
-@@ -11180,6 +11188,14 @@
+@@ -11193,6 +11201,14 @@
save_proc_info=thd->proc_info;
thd_proc_info(thd, "removing tmp table");
{
--- a/sql/sys_vars.cc
+++ b/sql/sys_vars.cc
-@@ -972,6 +972,29 @@
+@@ -972,6 +972,36 @@
NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(0),
ON_UPDATE(update_cached_long_query_time));
+ NO_CMD_LINE, VALID_RANGE(0, LONG_TIMEOUT), DEFAULT(0),
+ NO_MUTEX_GUARD, IN_BINLOG, ON_CHECK(0),
+ ON_UPDATE(update_cached_query_exec_time));
++static Sys_var_ulong sys_query_exec_id(
++ "query_exec_id",
++ "Pretend queries take this query id. When 0 (the default) use the"
++ "actual query id. Used only for debugging.",
++ SESSION_VAR(query_exec_id),
++ NO_CMD_LINE, VALID_RANGE(0, ULONG_MAX), DEFAULT(0), BLOCK_SIZE(1),
++ NO_MUTEX_GUARD, IN_BINLOG);
+#endif
+
static bool fix_low_prio_updates(sys_var *self, THD *thd, enum_var_type type)
{
if (type == OPT_SESSION)
-@@ -2898,6 +2921,117 @@
+@@ -2898,6 +2928,134 @@
DEFAULT(FALSE), NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(0),
ON_UPDATE(fix_log_state));
+ "Log queries replayed be the slave SQL thread",
+ GLOBAL_VAR(opt_log_slow_slave_statements), CMD_LINE(OPT_ARG),
+ DEFAULT(FALSE));
++static Sys_var_mybool Sys_log_slow_admin_statements(
++ "log_slow_admin_statements",
++ "Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements"
++ " to the slow log if it is open.",
++ GLOBAL_VAR(opt_log_slow_admin_statements), CMD_LINE(OPT_ARG),
++ DEFAULT(FALSE));
+static Sys_var_mybool Sys_log_slow_sp_statements(
+ "log_slow_sp_statements",
+ "Log slow statements executed by stored procedure to the slow log if it is open.",
+ "Log slow statements executed by stored procedure to the slow log if it is open. [second, microsecond]",
+ GLOBAL_VAR(opt_slow_query_log_timestamp_precision), CMD_LINE(REQUIRED_ARG),
+ slow_query_log_timestamp_precision_name, DEFAULT(SLOG_SECOND));
-+
++
++const char* slow_query_log_rate_name[]= {"session", "query", 0};
++static Sys_var_enum Sys_slow_query_log_rate_type(
++ "log_slow_rate_type",
++ "Choose the log_slow_rate_limit behavior: session or query. "
++ "When you choose 'session' - every %log_slow_rate_limit connection "
++ "will be processed to slow query log. "
++ "When you choose 'query' - every %log_slow_rate_limit query "
++ "will be processed to slow query log. "
++ "[session, query]",
++ GLOBAL_VAR(opt_slow_query_log_rate_type), CMD_LINE(REQUIRED_ARG),
++ slow_query_log_rate_name, DEFAULT(SLOG_RT_SESSION));
/* Synonym of "slow_query_log" for consistency with SHOW VARIABLES output */
static Sys_var_mybool Sys_log_slow(
"log_slow_queries",
# endif /* HAVE_PROFILING */
--- /dev/null
+++ b/mysql-test/include/log_grep.inc
-@@ -0,0 +1,17 @@
-+--disable_query_log
+@@ -0,0 +1,41 @@
+--echo [log_grep.inc] file: $log_file pattern: $grep_pattern
+perl;
+ $log_file= $ENV{'log_file'};
+ $log_file_full_path= $ENV{'log_file_full_path'};
-+ $grep_pattern= $ENV{'grep_pattern'};
-+
++ $log_slow_rate_test= $ENV{'log_slow_rate_test'};
+ open(FILE, "$log_file_full_path")
+ or die("Cannot open file $log_file_full_path: $!\n");
+
-+ $lines = 0;
-+ while(<FILE>) {
-+ $lines++ if (/$grep_pattern/);
++ if ($log_slow_rate_test) {
++ $one= 0;
++ $two= 0;
++ $three= 0;
++ while(<FILE>) {
++ $one++ if(/'connection_one'/);
++ $two++ if(/'connection_two'/);
++ $three++ if(/'connection_three'/);
++ }
++ $sum= $one + $two + $three;
++ $zero= 0;
++ if ($one == 0) {
++ $zero++;
++ }
++ if ($two == 0) {
++ $zero++;
++ }
++ if ($three == 0) {
++ $zero++;
++ }
++ print "[log_grep.inc] sum: $sum\n";
++ print "[log_grep.inc] zero: $zero\n";
++ }
++ else {
++ $grep_pattern= $ENV{'grep_pattern'};
++ $lines= 0;
++ while(<FILE>) {
++ $lines++ if (/$grep_pattern/);
++ }
++ print "[log_grep.inc] lines: $lines\n";
+ }
+ close(FILE);
-+ print "[log_grep.inc] lines: $lines\n";
+EOF
--- /dev/null
+++ b/mysql-test/include/log_start.inc
+EVAL SET GLOBAL slow_query_log_file="$log_file_full_path";
+SET GLOBAL slow_query_log=ON;
+--enable_query_log
-\ No newline at end of file
--- /dev/null
+++ b/mysql-test/include/log_stop.inc
@@ -0,0 +1,7 @@
+log_slow_filter full_join
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_filter.result
-@@ -0,0 +1,15 @@
+@@ -0,0 +1,16 @@
+CREATE TABLE t(id INT PRIMARY KEY);
+INSERT INTO t VALUES(1);
+INSERT INTO t VALUES(2);
+SET long_query_time=default;
+[log_grep.inc] file: percona.slow_extended.log_slow_filter pattern: Query_time
+[log_grep.inc] lines: 1
++DROP TABLE t;
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_slave_statements-cl.result
@@ -0,0 +1,6 @@
+log_slow_slave_statements ON
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_slave_statements-innodb.result
-@@ -0,0 +1,18 @@
+@@ -0,0 +1,19 @@
+include/master-slave.inc
+[connection master]
+DROP TABLE IF EXISTS t;
+[log_stop.inc] percona.slow_extended.log_slow_slave_statements-innodb
+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements-innodb pattern: InnoDB_IO_r_ops
+[log_grep.inc] lines: 1
++DROP TABLE t;
+include/rpl_end.inc
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_slave_statements.result
-@@ -0,0 +1,44 @@
+@@ -0,0 +1,45 @@
+include/master-slave.inc
+[connection master]
+DROP TABLE IF EXISTS t;
+[log_grep.inc] lines: 0
+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(7\)
+[log_grep.inc] lines: 1
++DROP TABLE t;
+include/rpl_end.inc
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_sp_statements-cl.result
+log_slow_sp_statements ON
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_sp_statements.result
-@@ -0,0 +1,24 @@
+@@ -0,0 +1,25 @@
+SET long_query_time=1;
+SET GLOBAL log_slow_sp_statements=ON;
+SET SESSION query_exec_time=0.1;
+SET long_query_time=default;
+[log_grep.inc] file: percona.slow_extended.log_slow_sp_statements pattern: Query_time
+[log_grep.inc] lines: 3
++DROP PROCEDURE test_f;
--- /dev/null
+++ b/mysql-test/r/percona_log_slow_verbosity-cl.result
@@ -0,0 +1,6 @@
+SHOW GLOBAL VARIABLES LIKE 'slow_query_log_use_global_control';
--- /dev/null
+++ b/mysql-test/r/percona_min_examined_row_limit.result
-@@ -0,0 +1,34 @@
+@@ -0,0 +1,35 @@
+drop table if exists t;
+create table t(id INT PRIMARY KEY);
+insert into t values(1);
+SET GLOBAL long_query_time=default;
+[log_grep.inc] file: percona.slow_extended.min_examined_row_limit pattern: Query_time
+[log_grep.inc] lines: 1
++DROP TABLE t;
--- /dev/null
+++ b/mysql-test/t/percona_min_examined_row_limit.test
@@ -0,0 +1,35 @@
+DROP TABLE t;
--- a/sql/log_event.cc
+++ b/sql/log_event.cc
-@@ -2380,6 +2380,14 @@
+@@ -2385,6 +2385,14 @@
start+= host.length;
}
}
/*
NOTE: When adding new status vars, please don't forget to update
the MAX_SIZE_LOG_EVENT_STATUS in log_event.h and update the function
-@@ -2866,6 +2874,17 @@
+@@ -2871,6 +2879,17 @@
data_written= master_data_written= uint4korr(pos);
pos+= 4;
break;
CHECK_SPACE(pos, end, 1);
--- a/sql/log_event.h
+++ b/sql/log_event.h
-@@ -342,6 +342,10 @@
+@@ -343,6 +343,10 @@
#define Q_INVOKER 11
+
+SET GLOBAL query_exec_time=default;
+SET SESSION query_exec_time=default;
+--- /dev/null
++++ b/mysql-test/r/percona_log_slow_global_control_default.result
+@@ -0,0 +1 @@
++SET GLOBAL slow_query_log_use_global_control=default;
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_global_control_default.test
+@@ -0,0 +1 @@
++SET GLOBAL slow_query_log_use_global_control=default;
+--- /dev/null
++++ b/mysql-test/r/percona_slow_extended_log_error.result
+@@ -0,0 +1,10 @@
++SET long_query_time=0;
++DROP TABLE IF EXISTS t1;
++CREATE TABLE t(a INT);
++[log_start.inc] percona.slow_extended.log_error
++CREATE TABLE t(a INT);
++ERROR 42S01: Table 't' already exists
++[log_stop.inc] percona.slow_extended.log_error
++[log_grep.inc] file: percona.slow_extended.log_error pattern: Last_errno: 1050
++[log_grep.inc] lines: 1
++DROP TABLE t;
+--- /dev/null
++++ b/mysql-test/t/percona_slow_extended_log_error.test
+@@ -0,0 +1,15 @@
++--let log_file=percona.slow_extended.log_error
++SET long_query_time=0;
++--disable_warnings
++DROP TABLE IF EXISTS t1;
++--enable_warnings
++CREATE TABLE t(a INT);
++--source include/log_start.inc
++
++--error ER_TABLE_EXISTS_ERROR
++CREATE TABLE t(a INT);
++
++--source include/log_stop.inc
++--let grep_pattern = Last_errno: 1050
++--source include/log_grep.inc
++DROP TABLE t;
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_basic.test
+@@ -0,0 +1 @@
++SELECT @@global.log_slow_admin_statements;
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/r/log_slow_admin_statements_basic.result
+@@ -0,0 +1,3 @@
++SELECT @@global.log_slow_admin_statements;
++@@global.log_slow_admin_statements
++0
+--- /dev/null
++++ b/mysql-test/r/percona_log_slow_admin_statements.result
+@@ -0,0 +1,35 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements OFF
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS OFF
++SET GLOBAL log_slow_admin_statements=true;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements ON
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS ON
++SET GLOBAL log_slow_admin_statements=false;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements OFF
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS OFF
++SET GLOBAL log_slow_admin_statements=foo;
++ERROR 42000: Variable 'log_slow_admin_statements' can't be set to the value of 'foo'
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements OFF
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS OFF
++SET GLOBAL log_slow_admin_statements=default;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements OFF
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS OFF
+--- /dev/null
++++ b/mysql-test/r/percona_log_slow_admin_statements-config_false.result
+@@ -0,0 +1,6 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements OFF
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS OFF
+--- /dev/null
++++ b/mysql-test/r/percona_log_slow_admin_statements-config_foo.result
+@@ -0,0 +1,7 @@
++call mtr.add_suppression("option 'log_slow_admin_statements': boolean value 'foo' wasn't recognized. Set to OFF.");
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements OFF
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS OFF
+--- /dev/null
++++ b/mysql-test/r/percona_log_slow_admin_statements-config_true.result
+@@ -0,0 +1,6 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements ON
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS ON
+--- /dev/null
++++ b/mysql-test/r/percona_log_slow_admin_statements-config.result
+@@ -0,0 +1,6 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++Variable_name Value
++log_slow_admin_statements ON
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++VARIABLE_NAME VARIABLE_VALUE
++LOG_SLOW_ADMIN_STATEMENTS ON
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config_false.cnf
+@@ -0,0 +1,2 @@
++[mysqld.1]
++log-slow-admin-statements=false
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config_foo.cnf
+@@ -0,0 +1,2 @@
++[mysqld.1]
++log-slow-admin-statements=foo
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config_true.cnf
+@@ -0,0 +1,2 @@
++[mysqld.1]
++log-slow-admin-statements=true
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config.cnf
+@@ -0,0 +1,2 @@
++[mysqld.1]
++log-slow-admin-statements
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements.test
+@@ -0,0 +1,20 @@
++# default value
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++# set value to 'true'
++SET GLOBAL log_slow_admin_statements=true;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++# set value to 'false'
++SET GLOBAL log_slow_admin_statements=false;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++# set value to 'foo'
++--error ER_WRONG_VALUE_FOR_VAR
++SET GLOBAL log_slow_admin_statements=foo;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
++# set value to default
++SET GLOBAL log_slow_admin_statements=default;
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config_false.test
+@@ -0,0 +1,2 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config_foo.test
+@@ -0,0 +1,3 @@
++call mtr.add_suppression("option 'log_slow_admin_statements': boolean value 'foo' wasn't recognized. Set to OFF.");
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config_true.test
+@@ -0,0 +1,2 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
+--- /dev/null
++++ b/mysql-test/t/percona_log_slow_admin_statements-config.test
+@@ -0,0 +1,2 @@
++SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
++SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
+--- a/mysql-test/r/mysqld--help-notwin.result
++++ b/mysql-test/r/mysqld--help-notwin.result
+@@ -250,15 +250,38 @@
+ --log-slow-admin-statements
+ Log slow OPTIMIZE, ANALYZE, ALTER and other
+ administrative statements to the slow log if it is open.
++ --log-slow-filter=name
++ Log only the queries that followed certain execution
++ plan. Multiple flags allowed in a comma-separated string.
++ [qc_miss, full_scan, full_join, tmp_table,
++ tmp_table_on_disk, filesort, filesort_on_disk]
+ --log-slow-queries[=name]
+ Log slow queries to a table or log file. Defaults logging
+ to table mysql.slow_log or hostname-slow.log if
+ --log-output=file is used. Must be enabled to activate
+ other slow log options. Deprecated option, use
+ --slow-query-log/--slow-query-log-file instead.
++ --log-slow-rate-limit=#
++ Rate limit statement writes to slow log to only those
++ from every (1/log_slow_rate_limit) session.
++ --log-slow-rate-type=name
++ Choose the log_slow_rate_limit behavior: session or
++ query. When you choose 'session' - every
++ %log_slow_rate_limit connection will be processed to slow
++ query log. When you choose 'query' - every
++ %log_slow_rate_limit query will be processed to slow
++ query log. [session, query]
+ --log-slow-slave-statements
+- Log slow statements executed by slave thread to the slow
+- log if it is open.
++ Log queries replayed be the slave SQL thread
++ --log-slow-sp-statements
++ Log slow statements executed by stored procedure to the
++ slow log if it is open.
++ (Defaults to on; use --skip-log-slow-sp-statements to disable.)
++ --log-slow-verbosity=name
++ Choose how verbose the messages to your slow log will be.
++ Multiple flags allowed in a comma-separated string.
++ [microtime, query_plan, innodb, profiling,
++ profiling_use_getrusage]
+ --log-tc=name Path to transaction coordinator log (used for
+ transactions that affect more than one storage engine,
+ when binary log is disabled).
+@@ -660,6 +683,18 @@
+ Log slow queries to given log file. Defaults logging to
+ hostname-slow.log. Must be enabled to activate other slow
+ log options
++ --slow-query-log-timestamp-always
++ Timestamp is printed for all records of the slow log even
++ if they are same time.
++ --slow-query-log-timestamp-precision=name
++ Log slow statements executed by stored procedure to the
++ slow log if it is open. [second, microsecond]
++ --slow-query-log-use-global-control=name
++ Choose flags, wich always use the global variables.
++ Multiple flags allowed in a comma-separated string.
++ [none, log_slow_filter, log_slow_rate_limit,
++ log_slow_verbosity, long_query_time,
++ min_examined_row_limit, all]
+ --socket=name Socket file to use for connection
+ --sort-buffer-size=#
+ Each thread that needs to do a sort allocates a buffer of
+@@ -817,7 +852,12 @@
+ log-short-format FALSE
+ log-slave-updates FALSE
+ log-slow-admin-statements FALSE
++log-slow-filter
++log-slow-rate-limit 1
++log-slow-rate-type session
+ log-slow-slave-statements FALSE
++log-slow-sp-statements TRUE
++log-slow-verbosity
+ log-tc tc.log
+ log-tc-size 24576
+ log-warnings 1
+@@ -933,6 +973,9 @@
+ slave-type-conversions
+ slow-launch-time 2
+ slow-query-log FALSE
++slow-query-log-timestamp-always FALSE
++slow-query-log-timestamp-precision second
++slow-query-log-use-global-control
+ sort-buffer-size 2097152
+ sporadic-binlog-dump-fail FALSE
+ sql-mode
+--- /dev/null
++++ b/mysql-test/r/percona_slow_query_log_rate.result
+@@ -0,0 +1,78 @@
++SET GLOBAL long_query_time=1;
++SET GLOBAL log_slow_rate_type='session';
++SET GLOBAL log_slow_rate_limit=3;
++[log_start.inc] percona.slow_extended.log_slow_rate_limit
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=1;
++SELECT 'connection_one';
++connection_one
++connection_one
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=2;
++SELECT 'connection_two';
++connection_two
++connection_two
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=3;
++SELECT 'connection_three';
++connection_three
++connection_three
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=4;
++SELECT 'connection_one';
++connection_one
++connection_one
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=5;
++SELECT 'connection_two';
++connection_two
++connection_two
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=6;
++SELECT 'connection_three';
++connection_three
++connection_three
++[log_stop.inc] percona.slow_extended.log_slow_rate_limit
++[log_grep.inc] file: percona.slow_extended.log_slow_rate_limit pattern:
++[log_grep.inc] sum: 2
++[log_grep.inc] zero: 2
++SET GLOBAL log_slow_rate_type='query';
++SET GLOBAL log_slow_rate_limit=2;
++[log_start.inc] percona.slow_extended.log_slow_rate_limit
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=1;
++SELECT 'connection_one';
++connection_one
++connection_one
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=2;
++SELECT 'connection_two';
++connection_two
++connection_two
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=3;
++SELECT 'connection_three';
++connection_three
++connection_three
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=4;
++SELECT 'connection_one';
++connection_one
++connection_one
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=5;
++SELECT 'connection_two';
++connection_two
++connection_two
++SET SESSION query_exec_time=1.1;
++SET SESSION query_exec_id=6;
++SELECT 'connection_three';
++connection_three
++connection_three
++[log_stop.inc] percona.slow_extended.log_slow_rate_limit
++[log_grep.inc] file: percona.slow_extended.log_slow_rate_limit pattern:
++[log_grep.inc] sum: 3
++[log_grep.inc] zero: 0
++SET GLOBAL long_query_time=default;
++SET GLOBAL log_slow_rate_type=default;
++SET GLOBAL log_slow_rate_limit=default;
+--- /dev/null
++++ b/mysql-test/t/percona_slow_query_log_rate.test
+@@ -0,0 +1,16 @@
++--source include/have_debug.inc
++--let log_file=percona.slow_extended.log_slow_rate_limit
++
++SET GLOBAL long_query_time=1;
++
++SET GLOBAL log_slow_rate_type='session';
++SET GLOBAL log_slow_rate_limit=3;
++--source include/percona_slow_query_log_rate.inc
++
++SET GLOBAL log_slow_rate_type='query';
++SET GLOBAL log_slow_rate_limit=2;
++--source include/percona_slow_query_log_rate.inc
++
++SET GLOBAL long_query_time=default;
++SET GLOBAL log_slow_rate_type=default;
++SET GLOBAL log_slow_rate_limit=default;
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/t/log_slow_rate_limit_basic.test
+@@ -0,0 +1 @@
++SELECT @@global.log_slow_rate_limit;
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/r/log_slow_rate_limit_basic.result
+@@ -0,0 +1,3 @@
++SELECT @@global.log_slow_rate_limit;
++@@global.log_slow_rate_limit
++1
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/t/log_slow_rate_type_basic.test
+@@ -0,0 +1 @@
++SELECT @@global.log_slow_rate_type;
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/r/log_slow_rate_type_basic.result
+@@ -0,0 +1,3 @@
++SELECT @@global.log_slow_rate_type;
++@@global.log_slow_rate_type
++session
+--- /dev/null
++++ b/mysql-test/include/percona_slow_query_log_rate.inc
+@@ -0,0 +1,42 @@
++--let wait_condition=SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST;
++--connection default
++--source include/log_start.inc
++
++--connect (connection_one,localhost,root,,)
++--connect (connection_two,localhost,root,,)
++--connect (connection_three,localhost,root,,)
++
++--let i=2
++--let k=1
++
++while($i)
++{
++--connection connection_one
++SET SESSION query_exec_time=1.1;
++eval SET SESSION query_exec_id=$k;
++inc $k;
++SELECT 'connection_one';
++
++--connection connection_two
++SET SESSION query_exec_time=1.1;
++eval SET SESSION query_exec_id=$k;
++inc $k;
++SELECT 'connection_two';
++
++--connection connection_three
++SET SESSION query_exec_time=1.1;
++eval SET SESSION query_exec_id=$k;
++inc $k;
++SELECT 'connection_three';
++
++dec $i;
++}
++
++--connection default
++--disconnect connection_one
++--disconnect connection_two
++--disconnect connection_three
++--source include/wait_condition.inc
++--source include/log_stop.inc
++--let log_slow_rate_test=1
++--source include/log_grep.inc
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/r/query_exec_id_basic.result
+@@ -0,0 +1,2 @@
++SET GLOBAL query_exec_id=default;
++SET SESSION query_exec_id=default;
+--- /dev/null
++++ b/mysql-test/suite/sys_vars/t/query_exec_id_basic.test
+@@ -0,0 +1,4 @@
++--source include/have_debug.inc
++
++SET GLOBAL query_exec_id=default;
++SET SESSION query_exec_id=default;