# name : response-time-distribution.patch # introduced : 12 # maintainer : Oleg # #!!! notice !!! # Any small change to this file in the main branch # should be done or reviewed by the maintainer! diff -ruN a/CMakeLists.txt b/CMakeLists.txt --- a/CMakeLists.txt 2011-03-31 17:36:18.000000000 +0400 +++ b/CMakeLists.txt 2011-04-09 19:12:12.000000000 +0400 @@ -165,7 +165,12 @@ OPTION (WITH_UNIT_TESTS "Compile MySQL with unit tests" ON) MARK_AS_ADVANCED(CYBOZU BACKUP_TEST WITHOUT_SERVER DISABLE_SHARED) - +OPTION(WITHOUT_RESPONSE_TIME_DISTRIBUTION "If we want to have response_time_distribution" OFF) +IF(WITHOUT_RESPONSE_TIME_DISTRIBUTION) +ELSE() +ADD_DEFINITIONS(-DHAVE_RESPONSE_TIME_DISTRIBUTION) +ENDIF() + OPTION(ENABLE_DEBUG_SYNC "Enable debug sync (debug builds only)" ON) IF(ENABLE_DEBUG_SYNC) SET(CMAKE_CXX_FLAGS_DEBUG "${CMAKE_CXX_FLAGS_DEBUG} -DENABLED_DEBUG_SYNC") diff -ruN a/include/mysql_com.h b/include/mysql_com.h --- a/include/mysql_com.h 2011-03-31 17:36:18.000000000 +0400 +++ b/include/mysql_com.h 2011-04-10 11:28:51.000000000 +0400 @@ -141,10 +141,11 @@ #define REFRESH_FAST 32768 /* Intern flag */ /* RESET (remove all queries) from query cache */ -#define REFRESH_QUERY_CACHE 65536 -#define REFRESH_QUERY_CACHE_FREE 0x20000L /* pack query cache */ -#define REFRESH_DES_KEY_FILE 0x40000L -#define REFRESH_USER_RESOURCES 0x80000L +#define REFRESH_QUERY_CACHE 65536 +#define REFRESH_QUERY_CACHE_FREE 0x20000L /* pack query cache */ +#define REFRESH_DES_KEY_FILE 0x40000L +#define REFRESH_USER_RESOURCES 0x80000L +#define REFRESH_QUERY_RESPONSE_TIME 0x100000L /* response time distibution */ #define CLIENT_LONG_PASSWORD 1 /* new more secure passwords */ #define CLIENT_FOUND_ROWS 2 /* Found instead of affected rows */ diff -ruN /dev/null b/patch_info/response-time-distribution.info --- /dev/null 1970-01-01 00:00:00.000000000 +0000 +++ b/patch_info/response-time-distribution.info 2011-04-09 19:12:12.000000000 +0400 @@ -0,0 +1,9 @@ +File=response-time-distribution.patch +Name=Response time distribution +Version=1.0 +Author=Percona +License=GPL +Comment= +Changelog +2010-07-02 first version avaliable +2010-09-15 add column 'total' diff -ruN a/sql/CMakeLists.txt b/sql/CMakeLists.txt --- a/sql/CMakeLists.txt 2011-03-31 17:36:18.000000000 +0400 +++ b/sql/CMakeLists.txt 2011-04-09 19:12:12.000000000 +0400 @@ -51,7 +51,7 @@ message.h mf_iocache.cc my_decimal.cc ../sql-common/my_time.c mysqld.cc net_serv.cc keycaches.cc ../sql-common/client_plugin.c - opt_range.cc opt_range.h opt_sum.cc + opt_range.cc opt_range.h query_response_time.h opt_sum.cc ../sql-common/pack.c parse_file.cc password.c procedure.cc protocol.cc records.cc repl_failsafe.cc rpl_filter.cc set_var.cc slave.cc sp.cc sp_cache.cc sp_head.cc sp_pcontext.cc @@ -59,7 +59,7 @@ sql_cache.cc sql_class.cc sql_client.cc sql_crypt.cc sql_crypt.h sql_cursor.cc sql_db.cc sql_delete.cc sql_derived.cc sql_do.cc sql_error.cc sql_handler.cc sql_help.cc sql_insert.cc sql_lex.cc - sql_list.cc sql_load.cc sql_manager.cc sql_parse.cc + sql_list.cc sql_load.cc sql_manager.cc sql_parse.cc query_response_time.cc sql_partition.cc sql_plugin.cc sql_prepare.cc sql_rename.cc debug_sync.cc debug_sync.h sql_repl.cc sql_select.cc sql_show.cc sql_state.c sql_string.cc diff -ruN a/sql/handler.h b/sql/handler.h --- a/sql/handler.h 2011-04-09 19:11:54.000000000 +0400 +++ b/sql/handler.h 2011-04-10 11:28:51.000000000 +0400 @@ -580,6 +580,7 @@ SCH_PROFILES, SCH_REFERENTIAL_CONSTRAINTS, SCH_PROCEDURES, + SCH_QUERY_RESPONSE_TIME, SCH_SCHEMATA, SCH_SCHEMA_PRIVILEGES, SCH_SESSION_STATUS, diff -ruN a/sql/lex.h b/sql/lex.h --- a/sql/lex.h 2011-03-31 17:36:18.000000000 +0400 +++ b/sql/lex.h 2011-04-10 11:28:52.000000000 +0400 @@ -426,6 +426,7 @@ { "PURGE", SYM(PURGE)}, { "QUARTER", SYM(QUARTER_SYM)}, { "QUERY", SYM(QUERY_SYM)}, + { "QUERY_RESPONSE_TIME", SYM(QUERY_RESPONSE_TIME_SYM)}, { "QUICK", SYM(QUICK)}, { "RANGE", SYM(RANGE_SYM)}, { "READ", SYM(READ_SYM)}, diff -ruN a/sql/mysqld.cc b/sql/mysqld.cc --- a/sql/mysqld.cc 2011-04-09 19:12:11.000000000 +0400 +++ b/sql/mysqld.cc 2011-04-10 11:28:52.000000000 +0400 @@ -69,6 +69,8 @@ #include "debug_sync.h" #include "sql_callback.h" +#include "query_response_time.h" + #ifdef WITH_PERFSCHEMA_STORAGE_ENGINE #include "../storage/perfschema/pfs_server.h" #endif /* WITH_PERFSCHEMA_STORAGE_ENGINE */ @@ -606,7 +608,7 @@ MY_LOCALE *my_default_lc_messages; MY_LOCALE *my_default_lc_time_names; -SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen, have_query_cache; +SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen, have_query_cache, have_response_time_distribution; SHOW_COMP_OPTION have_geometry, have_rtree_keys; SHOW_COMP_OPTION have_crypt, have_compress; SHOW_COMP_OPTION have_profiling; @@ -907,6 +909,10 @@ my_bool opt_enable_shared_memory; HANDLE smem_event_connect_request= 0; #endif +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION +ulong opt_query_response_time_range_base = QRT_DEFAULT_BASE; +my_bool opt_query_response_time_stats= 0; +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION my_bool opt_use_ssl = 0; char *opt_ssl_ca= NULL, *opt_ssl_capath= NULL, *opt_ssl_cert= NULL, @@ -1478,6 +1484,9 @@ my_free(opt_bin_logname); bitmap_free(&temp_pool); free_max_user_conn(); +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + query_response_time_free(); +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION #ifdef HAVE_REPLICATION end_slave_list(); #endif @@ -3960,6 +3969,9 @@ if (!DEFAULT_ERRMSGS[0][0]) unireg_abort(1); +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + query_response_time_init(); +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION /* We have to initialize the storage engines before CSV logging */ if (ha_init()) { @@ -6848,6 +6860,11 @@ #else have_query_cache=SHOW_OPTION_NO; #endif +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + have_response_time_distribution= SHOW_OPTION_YES; +#else // HAVE_RESPONSE_TIME_DISTRIBUTION + have_response_time_distribution= SHOW_OPTION_NO; +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION #ifdef HAVE_SPATIAL have_geometry=SHOW_OPTION_YES; #else diff -ruN a/sql/mysqld.h b/sql/mysqld.h --- a/sql/mysqld.h 2011-04-09 19:12:11.000000000 +0400 +++ b/sql/mysqld.h 2011-04-10 11:28:52.000000000 +0400 @@ -98,6 +98,10 @@ extern bool opt_disable_networking, opt_skip_show_db; extern bool opt_skip_name_resolve; extern bool opt_ignore_builtin_innodb; +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION +extern ulong opt_query_response_time_range_base; +extern my_bool opt_query_response_time_stats; +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION extern my_bool opt_character_set_client_handshake; extern bool volatile abort_loop; extern bool in_bootstrap; diff -ruN /dev/null b/sql/query_response_time.cc --- /dev/null 1970-01-01 00:00:00.000000000 +0000 +++ b/sql/query_response_time.cc 2011-04-10 00:27:11.000000000 +0400 @@ -0,0 +1,310 @@ +#include "mysql_version.h" +#include "my_global.h" +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION +#include "mysql_com.h" +#include "rpl_tblmap.h" +#include "table.h" +#include "field.h" +#include "sql_show.h" +#include "query_response_time.h" + +#define TIME_STRING_POSITIVE_POWER_LENGTH QRT_TIME_STRING_POSITIVE_POWER_LENGTH +#define TIME_STRING_NEGATIVE_POWER_LENGTH 6 +#define TOTAL_STRING_POSITIVE_POWER_LENGTH QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH +#define TOTAL_STRING_NEGATIVE_POWER_LENGTH 6 +#define MINIMUM_BASE 2 +#define MAXIMUM_BASE QRT_MAXIMUM_BASE +#define POSITIVE_POWER_FILLER QRT_POSITIVE_POWER_FILLER +#define NEGATIVE_POWER_FILLER QRT_NEGATIVE_POWER_FILLER +#define STRING_OVERFLOW QRT_STRING_OVERFLOW +#define TIME_OVERFLOW QRT_TIME_OVERFLOW +#define DEFAULT_BASE QRT_DEFAULT_BASE + +#define do_xstr(s) do_str(s) +#define do_str(s) #s +#define do_format(filler,width) "%" filler width "lld" +/* + Format strings for snprintf. Generate from: + POSITIVE_POWER_FILLER and TIME_STRING_POSITIVE_POWER_LENGTH + NEFATIVE_POWER_FILLER and TIME_STRING_NEGATIVE_POWER_LENGTH +*/ +#define TIME_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TIME_STRING_POSITIVE_POWER_LENGTH)) +#define TIME_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TIME_STRING_NEGATIVE_POWER_LENGTH)) +#define TIME_STRING_FORMAT TIME_STRING_POSITIVE_POWER_FORMAT "." TIME_STRING_NEGATIVE_POWER_FORMAT + +#define TOTAL_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TOTAL_STRING_POSITIVE_POWER_LENGTH)) +#define TOTAL_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TOTAL_STRING_NEGATIVE_POWER_LENGTH)) +#define TOTAL_STRING_FORMAT TOTAL_STRING_POSITIVE_POWER_FORMAT "." TOTAL_STRING_NEGATIVE_POWER_FORMAT + +#define TIME_STRING_LENGTH QRT_TIME_STRING_LENGTH +#define TIME_STRING_BUFFER_LENGTH (TIME_STRING_LENGTH + 1 /* '\0' */) + +#define TOTAL_STRING_LENGTH QRT_TOTAL_STRING_LENGTH +#define TOTAL_STRING_BUFFER_LENGTH (TOTAL_STRING_LENGTH + 1 /* '\0' */) + +/* + Calculate length of "log linear" + 1) + (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH) < (MINIMUM_BASE ^ (result + 1)) + + 2) + (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH) + and + (MINIMUM_BASE ^ (result + 1)) > (10 ^ STRING_POWER_LENGTH) + + 3) + result <= LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) + result + 1 > LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) + + 4) STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) - 1 < result <= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) + + MINIMUM_BASE= 2 always, LOG(MINIMUM_BASE,10)= 3.3219280948873626, result= (int)3.3219280948873626 * STRING_POWER_LENGTH + + Last counter always use for time overflow +*/ +#define POSITIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_POSITIVE_POWER_LENGTH)) +#define NEGATIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_NEGATIVE_POWER_LENGTH)) +#define OVERALL_POWER_COUNT (NEGATIVE_POWER_COUNT + 1 + POSITIVE_POWER_COUNT) + +#define MILLION ((unsigned long)1000 * 1000) + +namespace query_response_time +{ + +class utility +{ +public: + utility() : m_base(0) + { + m_max_dec_value= MILLION; + for(int i= 0; TIME_STRING_POSITIVE_POWER_LENGTH > i; ++i) + m_max_dec_value *= 10; + setup(DEFAULT_BASE); + } +public: + uint base() const { return m_base; } + uint negative_count() const { return m_negative_count; } + uint positive_count() const { return m_positive_count; } + uint bound_count() const { return m_bound_count; } + ulonglong max_dec_value() const { return m_max_dec_value; } + ulonglong bound(uint index) const { return m_bound[ index ]; } +public: + void setup(uint base) + { + if(base != m_base) + { + m_base= base; + + const ulonglong million= 1000 * 1000; + ulonglong value= million; + m_negative_count= 0; + while(value > 0) + { + m_negative_count += 1; + value /= m_base; + } + m_negative_count -= 1; + + value= million; + m_positive_count= 0; + while(value < m_max_dec_value) + { + m_positive_count += 1; + value *= m_base; + } + m_bound_count= m_negative_count + m_positive_count; + + value= million; + for(uint i= 0; i < m_negative_count; ++i) + { + value /= m_base; + m_bound[m_negative_count - i - 1]= value; + } + value= million; + for(uint i= 0; i < m_positive_count; ++i) + { + m_bound[m_negative_count + i]= value; + value *= m_base; + } + } + } +private: + uint m_base; + uint m_negative_count; + uint m_positive_count; + uint m_bound_count; + ulonglong m_max_dec_value; /* for TIME_STRING_POSITIVE_POWER_LENGTH=7 is 10000000 */ + ulonglong m_bound[OVERALL_POWER_COUNT]; +}; + +void print_time(char* buffer, std::size_t buffer_size, std::size_t string_positive_power_length, const char* format, uint64 value) +{ + memset(buffer,'X',buffer_size); + buffer[string_positive_power_length]= '.'; + ulonglong second= (value / MILLION); + ulonglong microsecond= (value % MILLION); + std::size_t result_length= snprintf(buffer,buffer_size,format,second,microsecond); + if(result_length < 0) + { + assert(sizeof(STRING_OVERFLOW) <= buffer_size); + memcpy(buffer, STRING_OVERFLOW, sizeof(STRING_OVERFLOW)); + return; + } + buffer[result_length]= 0; +} + +class time_collector +{ +public: + time_collector(utility& u) : m_utility(&u) + { + my_atomic_rwlock_init(&time_collector_lock); + } + ~time_collector() + { + my_atomic_rwlock_destroy(&time_collector_lock); + } + uint32 count(uint index) const + { + my_atomic_rwlock_rdlock(&time_collector_lock); + uint32 result= my_atomic_load32((volatile int32*)&m_count[index]); + my_atomic_rwlock_rdunlock(&time_collector_lock); + return result; + } + uint64 total(uint index) const + { + my_atomic_rwlock_rdlock(&time_collector_lock); + uint64 result= my_atomic_load64((volatile int64*)&m_total[index]); + my_atomic_rwlock_rdunlock(&time_collector_lock); + return result; + } +public: + void flush() + { + my_atomic_rwlock_wrlock(&time_collector_lock); + memset((void*)&m_count,0,sizeof(m_count)); + memset((void*)&m_total,0,sizeof(m_total)); + my_atomic_rwlock_wrunlock(&time_collector_lock); + } + void collect(uint64 time) + { + int i= 0; + for(int count= m_utility->bound_count(); count > i; ++i) + { + if(m_utility->bound(i) > time) + { + my_atomic_rwlock_wrlock(&time_collector_lock); + my_atomic_add32((volatile int32*)(&m_count[i]), 1); + my_atomic_add64((volatile int64*)(&m_total[i]), time); + my_atomic_rwlock_wrunlock(&time_collector_lock); + break; + } + } + } +private: + utility* m_utility; + /* The lock for atomic operations on m_count and m_total. Only actually + used on architectures that do not have atomic implementation of atomic + operations. */ + my_atomic_rwlock_t time_collector_lock; + volatile uint32 m_count[OVERALL_POWER_COUNT + 1]; + volatile uint64 m_total[OVERALL_POWER_COUNT + 1]; +}; + +class collector +{ +public: + collector() : m_time(m_utility) + { + m_utility.setup(DEFAULT_BASE); + m_time.flush(); + } +public: + void flush() + { + m_utility.setup(opt_query_response_time_range_base); + m_time.flush(); + } + int fill(THD* thd, TABLE_LIST *tables, COND *cond) + { + DBUG_ENTER("fill_schema_query_response_time"); + TABLE *table= static_cast(tables->table); + Field **fields= table->field; + for(uint i= 0, count= bound_count() + 1 /* with overflow */; count > i; ++i) + { + char time[TIME_STRING_BUFFER_LENGTH]; + char total[TOTAL_STRING_BUFFER_LENGTH]; + if(i == bound_count()) + { + assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH); + assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH); + memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW)); + memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW)); + } + else + { + print_time(time,sizeof(time),TIME_STRING_POSITIVE_POWER_LENGTH,TIME_STRING_FORMAT,this->bound(i)); + print_time(total,sizeof(total),TOTAL_STRING_POSITIVE_POWER_LENGTH,TOTAL_STRING_FORMAT,this->total(i)); + } + fields[0]->store(time,strlen(time),system_charset_info); + fields[1]->store(this->count(i)); + fields[2]->store(total,strlen(total),system_charset_info); + if (schema_table_store_record(thd, table)) + { + DBUG_RETURN(1); + } + } + DBUG_RETURN(0); + } + void collect(ulonglong time) + { + m_time.collect(time); + } + uint bound_count() const + { + return m_utility.bound_count(); + } + ulonglong bound(uint index) + { + return m_utility.bound(index); + } + ulonglong count(uint index) + { + return m_time.count(index); + } + ulonglong total(uint index) + { + return m_time.total(index); + } +private: + utility m_utility; + time_collector m_time; +}; + +static collector g_collector; + +} // namespace query_response_time + +void query_response_time_init() +{ +} + +void query_response_time_free() +{ + query_response_time::g_collector.flush(); +} + +void query_response_time_flush() +{ + query_response_time::g_collector.flush(); +} +void query_response_time_collect(ulonglong query_time) +{ + query_response_time::g_collector.collect(query_time); +} + +int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond) +{ + return query_response_time::g_collector.fill(thd,tables,cond); +} +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION diff -ruN /dev/null b/sql/query_response_time.h --- /dev/null 1970-01-01 00:00:00.000000000 +0000 +++ b/sql/query_response_time.h 2011-04-09 19:12:12.000000000 +0400 @@ -0,0 +1,71 @@ +#ifndef QUERY_RESPONSE_TIME_H +#define QUERY_RESPONSE_TIME_H + +/* + Settings for query response time +*/ + +/* + Maximum string length for (10 ^ (-1 * QRT_STRING_NEGATIVE_POWER_LENGTH)) in text representation. + Example: for 6 is 0.000001 + Always 2 + + Maximum string length for (10 ^ (QRT_STRING_POSITIVE_POWER_LENGTH + 1) - 1) in text representation. + Example: for 7 is 9999999.0 +*/ +#define QRT_TIME_STRING_POSITIVE_POWER_LENGTH 7 +#define QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH 7 + +/* + Minimum base for log - ALWAYS 2 + Maximum base for log: +*/ +#define QRT_MAXIMUM_BASE 1000 + +/* + Filler for whole number (positive power) + Example: for + QRT_POSITIVE_POWER_FILLER ' ' + QRT_POSITIVE_POWER_LENGTH 7 + and number 7234 result is: + ' 7234' +*/ +#define QRT_POSITIVE_POWER_FILLER " " +/* + Filler for fractional number. Similiary to whole number +*/ +#define QRT_NEGATIVE_POWER_FILLER "0" + +/* + Message if string overflow (string overflow - internal error, this string say about bug in QRT) +*/ +#define QRT_STRING_OVERFLOW "TOO BIG STRING" + +/* + Message if time too big for statistic collecting (very long query) +*/ +#define QRT_TIME_OVERFLOW "TOO LONG" + +#define QRT_DEFAULT_BASE 10 + +#define QRT_TIME_STRING_LENGTH \ + max( (QRT_TIME_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TIME_STRING_NEGATIVE_POWER_LENGTH*/), \ + max( (sizeof(QRT_TIME_OVERFLOW) - 1), \ + (sizeof(QRT_STRING_OVERFLOW) - 1) ) ) + +#define QRT_TOTAL_STRING_LENGTH \ + max( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \ + max( (sizeof(QRT_TIME_OVERFLOW) - 1), \ + (sizeof(QRT_STRING_OVERFLOW) - 1) ) ) + +extern ST_SCHEMA_TABLE query_response_time_table; + +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION +extern void query_response_time_init (); +extern void query_response_time_free (); +extern void query_response_time_flush (); +extern void query_response_time_collect(ulonglong query_time); +extern int query_response_time_fill (THD* thd, TABLE_LIST *tables, COND *cond); +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION + +#endif // QUERY_RESPONSE_TIME_H diff -ruN a/sql/set_var.h b/sql/set_var.h --- a/sql/set_var.h 2011-03-31 17:36:18.000000000 +0400 +++ b/sql/set_var.h 2011-04-09 19:12:12.000000000 +0400 @@ -293,6 +293,7 @@ extern SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen; extern SHOW_COMP_OPTION have_query_cache; +extern SHOW_COMP_OPTION have_response_time_distribution; extern SHOW_COMP_OPTION have_geometry, have_rtree_keys; extern SHOW_COMP_OPTION have_crypt; extern SHOW_COMP_OPTION have_compress; diff -ruN a/sql/sql_parse.cc b/sql/sql_parse.cc --- a/sql/sql_parse.cc 2011-04-09 19:12:10.000000000 +0400 +++ b/sql/sql_parse.cc 2011-04-10 11:28:51.000000000 +0400 @@ -88,6 +88,7 @@ #include "sp_cache.h" #include "events.h" #include "sql_trigger.h" +#include "query_response_time.h" #include "transaction.h" #include "sql_audit.h" #include "sql_prepare.h" @@ -1482,22 +1483,74 @@ Do not log administrative statements unless the appropriate option is set. */ + #ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + if (opt_query_response_time_stats || thd->enable_slow_log) +#else // HAVE_RESPONSE_TIME_DISTRIBUTION if (thd->enable_slow_log) +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION { - ulonglong end_utime_of_query= thd->current_utime(); - thd_proc_info(thd, "logging slow query"); + ulonglong end_utime_of_query = thd->current_utime(); + ulonglong query_execution_time = end_utime_of_query - thd->utime_after_lock; +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + +#define DBUG_TEST_QRT(t,v) \ + DBUG_EXECUTE_IF(t, \ + { \ + query_execution_time= v; \ + DBUG_SET("-d,"t); \ + }) + + DBUG_EXECUTE_IF("query_exec_time_debug", query_execution_time= 0; ); + + DBUG_TEST_QRT("query_exec_time_0.31", 310000UL); + DBUG_TEST_QRT("query_exec_time_0.32", 320000UL); + DBUG_TEST_QRT("query_exec_time_0.33", 330000UL); + DBUG_TEST_QRT("query_exec_time_0.34", 340000UL); + DBUG_TEST_QRT("query_exec_time_0.35", 350000UL); + DBUG_TEST_QRT("query_exec_time_0.36", 360000UL); + DBUG_TEST_QRT("query_exec_time_0.37", 370000UL); + DBUG_TEST_QRT("query_exec_time_0.38", 380000UL); + DBUG_TEST_QRT("query_exec_time_0.39", 390000UL); + DBUG_TEST_QRT("query_exec_time_0.4", 400000UL); + DBUG_TEST_QRT("query_exec_time_0.5", 500000UL); + DBUG_TEST_QRT("query_exec_time_1.1", 1100000UL); + DBUG_TEST_QRT("query_exec_time_1.2", 1200000UL); + DBUG_TEST_QRT("query_exec_time_1.3", 1300000UL); + DBUG_TEST_QRT("query_exec_time_1.4", 1400000UL); + DBUG_TEST_QRT("query_exec_time_1.5", 1500000UL); + DBUG_TEST_QRT("query_exec_time_2.1", 2100000UL); + DBUG_TEST_QRT("query_exec_time_2.3", 2300000UL); + DBUG_TEST_QRT("query_exec_time_2.5", 2500000UL); + + DBUG_EXECUTE_IF("query_exec_time_debug", + if (query_execution_time == 0) + opt_query_response_time_stats= 0; + else + opt_query_response_time_stats= 1;); - 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 && - !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) && - thd->examined_row_count >= thd->variables.min_examined_row_limit) +#undef DBUG_TEST_QRT + + if(opt_query_response_time_stats) + { + query_response_time_collect(query_execution_time); + } +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION + if (thd->enable_slow_log) { thd_proc_info(thd, "logging slow query"); - thd->status_var.long_query_count++; - slow_log_print(thd, thd->query(), thd->query_length(), - end_utime_of_query); + + 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 && + !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) && + thd->examined_row_count >= thd->variables.min_examined_row_limit) + { + thd_proc_info(thd, "logging slow query"); + thd->status_var.long_query_count++; + slow_log_print(thd, thd->query(), thd->query_length(), + end_utime_of_query); + } } } DBUG_VOID_RETURN; @@ -1616,6 +1669,7 @@ case SCH_CHARSETS: case SCH_ENGINES: case SCH_COLLATIONS: + case SCH_QUERY_RESPONSE_TIME: case SCH_COLLATION_CHARACTER_SET_APPLICABILITY: case SCH_USER_PRIVILEGES: case SCH_SCHEMA_PRIVILEGES: diff -ruN a/sql/sql_reload.cc b/sql/sql_reload.cc --- a/sql/sql_reload.cc 2011-03-31 17:36:18.000000000 +0400 +++ b/sql/sql_reload.cc 2011-04-10 11:28:51.000000000 +0400 @@ -25,7 +25,7 @@ #include "hostname.h" // hostname_cache_refresh #include "sql_repl.h" // reset_master, reset_slave #include "debug_sync.h" - +#include "query_response_time.h" /** Reload/resets privileges and the different caches. @@ -296,6 +296,12 @@ #endif if (options & REFRESH_USER_RESOURCES) reset_mqh((LEX_USER *) NULL, 0); /* purecov: inspected */ +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + if (options & REFRESH_QUERY_RESPONSE_TIME) + { + query_response_time_flush(); + } +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION if (*write_to_binlog != -1) *write_to_binlog= tmp_write_to_binlog; /* diff -ruN a/sql/sql_show.cc b/sql/sql_show.cc --- a/sql/sql_show.cc 2011-04-09 19:12:10.000000000 +0400 +++ b/sql/sql_show.cc 2011-04-10 11:28:51.000000000 +0400 @@ -50,6 +50,7 @@ #include "event_data_objects.h" #endif #include +#include "query_response_time.h" #include "lock.h" // MYSQL_OPEN_IGNORE_FLUSH #include "debug_sync.h" #include "datadict.h" // dd_frm_type() @@ -7830,6 +7831,14 @@ */ +ST_FIELD_INFO query_response_time_fields_info[] = + { + {"time", QRT_TIME_STRING_LENGTH, MYSQL_TYPE_STRING, 0, 0, "", SKIP_OPEN_TABLE }, + {"count", MY_INT32_NUM_DECIMAL_DIGITS, MYSQL_TYPE_LONG, 0, MY_I_S_UNSIGNED, "", SKIP_OPEN_TABLE }, + {"total", QRT_TIME_STRING_LENGTH, MYSQL_TYPE_STRING, 0, 0, "", SKIP_OPEN_TABLE }, + {0, 0, MYSQL_TYPE_STRING, 0, 0, 0, SKIP_OPEN_TABLE } + }; + ST_SCHEMA_TABLE schema_tables[]= { {"CHARACTER_SETS", charsets_fields_info, create_schema_table, @@ -7883,6 +7892,13 @@ 1, 9, 0, OPTIMIZE_I_S_TABLE|OPEN_TABLE_ONLY}, {"ROUTINES", proc_fields_info, create_schema_table, fill_schema_proc, make_proc_old_format, 0, -1, -1, 0, 0}, +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table, + query_response_time_fill, make_old_format, 0, -1, -1, 0, 0}, +#else + {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table, + 0, make_old_format, 0, -1, -1, 0, 0}, +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION {"SCHEMATA", schema_fields_info, create_schema_table, fill_schema_schemata, make_schemata_old_format, 0, 1, -1, 0, 0}, {"SCHEMA_PRIVILEGES", schema_privileges_fields_info, create_schema_table, diff -ruN a/sql/sql_yacc.yy b/sql/sql_yacc.yy --- a/sql/sql_yacc.yy 2011-04-09 19:11:54.000000000 +0400 +++ b/sql/sql_yacc.yy 2011-04-10 11:28:52.000000000 +0400 @@ -1193,6 +1193,7 @@ %token PURGE %token QUARTER_SYM %token QUERY_SYM +%token QUERY_RESPONSE_TIME_SYM %token QUICK %token RANGE_SYM /* SQL-2003-R */ %token READS_SYM /* SQL-2003-R */ @@ -11076,6 +11077,15 @@ { Lex->sql_command = SQLCOM_SHOW_SLAVE_STAT; } + | QUERY_RESPONSE_TIME_SYM wild_and_where + { +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + LEX *lex= Lex; + lex->sql_command= SQLCOM_SELECT; + if (prepare_schema_table(YYTHD, lex, 0, SCH_QUERY_RESPONSE_TIME)) + MYSQL_YYABORT; +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION + } | CREATE PROCEDURE_SYM sp_name { LEX *lex= Lex; @@ -11312,6 +11322,12 @@ { Lex->type|= REFRESH_STATUS; } | SLAVE { Lex->type|= REFRESH_SLAVE; } + | QUERY_RESPONSE_TIME_SYM + { +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION + Lex->type|= REFRESH_QUERY_RESPONSE_TIME; +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION + } | MASTER_SYM { Lex->type|= REFRESH_MASTER; } | DES_KEY_FILE @@ -12597,6 +12613,7 @@ | PROXY_SYM {} | QUARTER_SYM {} | QUERY_SYM {} + | QUERY_RESPONSE_TIME_SYM {} | QUICK {} | READ_ONLY_SYM {} | REBUILD_SYM {} diff -ruN a/sql/sys_vars.cc b/sql/sys_vars.cc --- a/sql/sys_vars.cc 2011-04-09 19:12:11.000000000 +0400 +++ b/sql/sys_vars.cc 2011-04-10 11:28:51.000000000 +0400 @@ -49,6 +49,7 @@ #include "../storage/perfschema/pfs_server.h" #endif /* WITH_PERFSCHEMA_STORAGE_ENGINE */ +#include "query_response_time.h" /* This forward declaration is needed because including sql_base.h causes further includes. [TODO] Eliminate this forward declaration @@ -1837,6 +1838,26 @@ DEFAULT(FALSE)); #endif /* HAVE_QUERY_CACHE */ + +static Sys_var_have Sys_have_response_time_distribution( + "have_response_time_distribution", "have_response_time_distribution", + READ_ONLY GLOBAL_VAR(have_response_time_distribution), NO_CMD_LINE); + +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION +static Sys_var_mybool Sys_query_response_time_stats( + "query_response_time_stats", "Enable or disable query response time statisics collecting", + GLOBAL_VAR(opt_query_response_time_stats), CMD_LINE(OPT_ARG), + DEFAULT(FALSE)); + +static Sys_var_ulong Sys_query_response_time_range_base( + "query_response_time_range_base", + "Select base of log for query_response_time ranges. WARNING: variable change affect only after flush", + GLOBAL_VAR(opt_query_response_time_range_base), + CMD_LINE(REQUIRED_ARG), VALID_RANGE(2, QRT_MAXIMUM_BASE), + DEFAULT(QRT_DEFAULT_BASE), + BLOCK_SIZE(1)); +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION + static Sys_var_mybool Sys_secure_auth( "secure_auth", "Disallow authentication for accounts that have old (pre-4.1) "