response_time_distribution.patch

   1 # name       : response-time-distribution.patch
   2 # introduced : 12
   3 # maintainer : Oleg
   4 #
   5 #!!! notice !!!
   6 # Any small change to this file in the main branch
   7 # should be done or reviewed by the maintainer!
   8 diff -ruN a/CMakeLists.txt b/CMakeLists.txt
   9 --- a/CMakeLists.txt    2010-12-03 20:58:24.000000000 +0300
  10 +++ b/CMakeLists.txt    2011-01-16 20:11:28.000000000 +0300
  11 @@ -165,7 +165,12 @@
  12  OPTION (WITH_UNIT_TESTS "Compile MySQL with unit tests" ON)
  13  MARK_AS_ADVANCED(CYBOZU BACKUP_TEST WITHOUT_SERVER DISABLE_SHARED)
  14
  15 -
  16 +OPTION(WITHOUT_RESPONSE_TIME_DISTRIBUTION "If we want to have response_time_distribution" OFF)
  17 +IF(WITHOUT_RESPONSE_TIME_DISTRIBUTION)
  18 +ELSE()
  19 +ADD_DEFINITIONS(-DHAVE_RESPONSE_TIME_DISTRIBUTION)
  20 +ENDIF()
  21 +
  22  OPTION(ENABLE_DEBUG_SYNC "Enable debug sync (debug builds only)" ON)
  23  IF(ENABLE_DEBUG_SYNC)
  24    SET(CMAKE_CXX_FLAGS_DEBUG "${CMAKE_CXX_FLAGS_DEBUG} -DENABLED_DEBUG_SYNC")
  25 diff -ruN a/include/mysql_com.h b/include/mysql_com.h
  26 --- a/include/mysql_com.h       2010-12-03 20:58:24.000000000 +0300
  27 +++ b/include/mysql_com.h       2011-01-16 18:53:58.000000000 +0300
  28 @@ -137,10 +137,11 @@
  29  #define REFRESH_FAST           32768   /* Intern flag */
  30
  31  /* RESET (remove all queries) from query cache */
  32 -#define REFRESH_QUERY_CACHE    65536
  33 -#define REFRESH_QUERY_CACHE_FREE 0x20000L /* pack query cache */
  34 -#define REFRESH_DES_KEY_FILE   0x40000L
  35 -#define REFRESH_USER_RESOURCES 0x80000L
  36 +#define REFRESH_QUERY_CACHE         65536
  37 +#define REFRESH_QUERY_CACHE_FREE    0x20000L /* pack query cache */
  38 +#define REFRESH_DES_KEY_FILE        0x40000L
  39 +#define REFRESH_USER_RESOURCES      0x80000L
  40 +#define REFRESH_QUERY_RESPONSE_TIME 0x100000L /* response time distibution */
  41
  42  #define CLIENT_LONG_PASSWORD   1       /* new more secure passwords */
  43  #define CLIENT_FOUND_ROWS      2       /* Found instead of affected rows */
  44 diff -ruN a/patch_info/response-time-distribution.info b/patch_info/response-time-distribution.info
  45 --- a/patch_info/response-time-distribution.info        1970-01-01 03:00:00.000000000 +0300
  46 +++ b/patch_info/response-time-distribution.info        2011-01-16 18:53:59.000000000 +0300
  47 @@ -0,0 +1,9 @@
  48 +File=response-time-distribution.patch
  49 +Name=Response time distribution
  50 +Version=1.0
  51 +Author=Percona <info@percona.com>
  52 +License=GPL
  53 +Comment=
  54 +Changelog
  55 +2010-07-02 first version avaliable
  56 +2010-09-15 add column 'total'
  57 diff -ruN a/sql/CMakeLists.txt b/sql/CMakeLists.txt
  58 --- a/sql/CMakeLists.txt        2010-12-03 20:58:26.000000000 +0300
  59 +++ b/sql/CMakeLists.txt        2011-01-16 18:53:59.000000000 +0300
  60 @@ -51,7 +51,7 @@
  61                 message.h mf_iocache.cc my_decimal.cc ../sql-common/my_time.c
  62                 mysqld.cc net_serv.cc  keycaches.cc
  63                 ../sql-common/client_plugin.c
  64 -               opt_range.cc opt_range.h opt_sum.cc
  65 +               opt_range.cc opt_range.h query_response_time.h opt_sum.cc
  66                 ../sql-common/pack.c parse_file.cc password.c procedure.cc
  67                 protocol.cc records.cc repl_failsafe.cc rpl_filter.cc set_var.cc
  68                 slave.cc sp.cc sp_cache.cc sp_head.cc sp_pcontext.cc
  69 @@ -59,7 +59,7 @@
  70                 sql_cache.cc sql_class.cc sql_client.cc sql_crypt.cc sql_crypt.h
  71                 sql_cursor.cc sql_db.cc sql_delete.cc sql_derived.cc sql_do.cc
  72                 sql_error.cc sql_handler.cc sql_help.cc sql_insert.cc sql_lex.cc
  73 -               sql_list.cc sql_load.cc sql_manager.cc sql_parse.cc
  74 +               sql_list.cc sql_load.cc sql_manager.cc sql_parse.cc query_response_time.cc
  75                 sql_partition.cc sql_plugin.cc sql_prepare.cc sql_rename.cc
  76                 debug_sync.cc debug_sync.h
  77                 sql_repl.cc sql_select.cc sql_show.cc sql_state.c sql_string.cc
  78 diff -ruN a/sql/handler.h b/sql/handler.h
  79 --- a/sql/handler.h     2011-01-16 18:53:33.000000000 +0300
  80 +++ b/sql/handler.h     2011-01-16 18:54:00.000000000 +0300
  81 @@ -580,6 +580,7 @@
  82    SCH_PROFILES,
  83    SCH_REFERENTIAL_CONSTRAINTS,
  84    SCH_PROCEDURES,
  85 +  SCH_QUERY_RESPONSE_TIME,
  86    SCH_SCHEMATA,
  87    SCH_SCHEMA_PRIVILEGES,
  88    SCH_SESSION_STATUS,
  89 diff -ruN a/sql/lex.h b/sql/lex.h
  90 --- a/sql/lex.h 2010-12-03 20:58:26.000000000 +0300
  91 +++ b/sql/lex.h 2011-01-16 18:54:01.000000000 +0300
  92 @@ -426,6 +426,7 @@
  93    { "PURGE",           SYM(PURGE)},
  94    { "QUARTER",          SYM(QUARTER_SYM)},
  95    { "QUERY",           SYM(QUERY_SYM)},
  96 +  { "QUERY_RESPONSE_TIME", SYM(QUERY_RESPONSE_TIME_SYM)},
  97    { "QUICK",           SYM(QUICK)},
  98    { "RANGE",            SYM(RANGE_SYM)},
  99    { "READ",            SYM(READ_SYM)},
 100 diff -ruN a/sql/mysqld.cc b/sql/mysqld.cc
 101 --- a/sql/mysqld.cc     2011-01-16 18:53:35.000000000 +0300
 102 +++ b/sql/mysqld.cc     2011-01-17 02:22:27.000000000 +0300
 103 @@ -69,6 +69,8 @@
 104  #include "debug_sync.h"
 105  #include "sql_callback.h"
 106
 107 +#include "query_response_time.h"
 108 +
 109  #ifdef WITH_PERFSCHEMA_STORAGE_ENGINE
 110  #include "../storage/perfschema/pfs_server.h"
 111  #endif /* WITH_PERFSCHEMA_STORAGE_ENGINE */
 112 @@ -603,7 +605,7 @@
 113  MY_LOCALE *my_default_lc_messages;
 114  MY_LOCALE *my_default_lc_time_names;
 115
 116 -SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen, have_query_cache;
 117 +SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen, have_query_cache, have_response_time_distribution;
 118  SHOW_COMP_OPTION have_geometry, have_rtree_keys;
 119  SHOW_COMP_OPTION have_crypt, have_compress;
 120  SHOW_COMP_OPTION have_profiling;
 121 @@ -904,6 +906,10 @@
 122  my_bool opt_enable_shared_memory;
 123  HANDLE smem_event_connect_request= 0;
 124  #endif
 125 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 126 +ulong   opt_query_response_time_range_base  = QRT_DEFAULT_BASE;
 127 +my_bool opt_query_response_time_stats= 0;
 128 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 129
 130  my_bool opt_use_ssl  = 0;
 131  char *opt_ssl_ca= NULL, *opt_ssl_capath= NULL, *opt_ssl_cert= NULL,
 132 @@ -1472,6 +1478,9 @@
 133    my_free(opt_bin_logname);
 134    bitmap_free(&temp_pool);
 135    free_max_user_conn();
 136 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 137 +  query_response_time_free();
 138 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 139  #ifdef HAVE_REPLICATION
 140    end_slave_list();
 141  #endif
 142 @@ -3925,6 +3934,9 @@
 143    if (!DEFAULT_ERRMSGS[0][0])
 144      unireg_abort(1);
 145
 146 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 147 +  query_response_time_init();
 148 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 149    /* We have to initialize the storage engines before CSV logging */
 150    if (ha_init())
 151    {
 152 @@ -6797,6 +6809,11 @@
 153  #else
 154    have_query_cache=SHOW_OPTION_NO;
 155  #endif
 156 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 157 +  have_response_time_distribution= SHOW_OPTION_YES;
 158 +#else // HAVE_RESPONSE_TIME_DISTRIBUTION
 159 +  have_response_time_distribution= SHOW_OPTION_NO;
 160 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 161  #ifdef HAVE_SPATIAL
 162    have_geometry=SHOW_OPTION_YES;
 163  #else
 164 diff -ruN a/sql/mysqld.h b/sql/mysqld.h
 165 --- a/sql/mysqld.h      2011-01-16 18:53:35.000000000 +0300
 166 +++ b/sql/mysqld.h      2011-01-17 02:08:20.000000000 +0300
 167 @@ -98,6 +98,10 @@
 168  extern bool opt_disable_networking, opt_skip_show_db;
 169  extern bool opt_skip_name_resolve;
 170  extern bool opt_ignore_builtin_innodb;
 171 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 172 +extern ulong   opt_query_response_time_range_base;
 173 +extern my_bool opt_query_response_time_stats;
 174 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 175  extern my_bool opt_character_set_client_handshake;
 176  extern bool volatile abort_loop;
 177  extern bool in_bootstrap;
 178 diff -ruN a/sql/query_response_time.cc b/sql/query_response_time.cc
 179 --- a/sql/query_response_time.cc        1970-01-01 03:00:00.000000000 +0300
 180 +++ b/sql/query_response_time.cc        2011-01-17 02:13:08.000000000 +0300
 181 @@ -0,0 +1,372 @@
 182 +#include "mysql_version.h"
 183 +#ifdef __FreeBSD__
 184 +#include <sys/types.h>
 185 +#include <machine/atomic.h>
 186 +#endif // __FreeBSD__
 187 +#include "my_global.h"
 188 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 189 +#include "mysql_com.h"
 190 +#include "rpl_tblmap.h"
 191 +#include "table.h"
 192 +#include "field.h"
 193 +#include "sql_show.h"
 194 +#include "query_response_time.h"
 195 +
 196 +#define TIME_STRING_POSITIVE_POWER_LENGTH QRT_TIME_STRING_POSITIVE_POWER_LENGTH
 197 +#define TIME_STRING_NEGATIVE_POWER_LENGTH 6
 198 +#define TOTAL_STRING_POSITIVE_POWER_LENGTH QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH
 199 +#define TOTAL_STRING_NEGATIVE_POWER_LENGTH 6
 200 +#define MINIMUM_BASE 2
 201 +#define MAXIMUM_BASE QRT_MAXIMUM_BASE
 202 +#define POSITIVE_POWER_FILLER QRT_POSITIVE_POWER_FILLER
 203 +#define NEGATIVE_POWER_FILLER QRT_NEGATIVE_POWER_FILLER
 204 +#define STRING_OVERFLOW QRT_STRING_OVERFLOW
 205 +#define TIME_OVERFLOW   QRT_TIME_OVERFLOW
 206 +#define DEFAULT_BASE    QRT_DEFAULT_BASE
 207 +
 208 +#define do_xstr(s) do_str(s)
 209 +#define do_str(s) #s
 210 +#define do_format(filler,width) "%" filler width "lld"
 211 +/*
 212 +  Format strings for snprintf. Generate from:
 213 +  POSITIVE_POWER_FILLER and TIME_STRING_POSITIVE_POWER_LENGTH
 214 +  NEFATIVE_POWER_FILLER and TIME_STRING_NEGATIVE_POWER_LENGTH
 215 +*/
 216 +#define TIME_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TIME_STRING_POSITIVE_POWER_LENGTH))
 217 +#define TIME_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TIME_STRING_NEGATIVE_POWER_LENGTH))
 218 +#define TIME_STRING_FORMAT                   TIME_STRING_POSITIVE_POWER_FORMAT "." TIME_STRING_NEGATIVE_POWER_FORMAT
 219 +
 220 +#define TOTAL_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TOTAL_STRING_POSITIVE_POWER_LENGTH))
 221 +#define TOTAL_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TOTAL_STRING_NEGATIVE_POWER_LENGTH))
 222 +#define TOTAL_STRING_FORMAT                  TOTAL_STRING_POSITIVE_POWER_FORMAT "." TOTAL_STRING_NEGATIVE_POWER_FORMAT
 223 +
 224 +#define TIME_STRING_LENGTH     QRT_TIME_STRING_LENGTH
 225 +#define TIME_STRING_BUFFER_LENGTH      (TIME_STRING_LENGTH + 1 /* '\0' */)
 226 +
 227 +#define TOTAL_STRING_LENGTH    QRT_TOTAL_STRING_LENGTH
 228 +#define TOTAL_STRING_BUFFER_LENGTH     (TOTAL_STRING_LENGTH + 1 /* '\0' */)
 229 +
 230 +/*
 231 +  Calculate length of "log linear"
 232 +  1)
 233 +  (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH) < (MINIMUM_BASE ^ (result + 1))
 234 +
 235 +  2)
 236 +  (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH)
 237 +  and
 238 +  (MINIMUM_BASE ^ (result + 1)) > (10 ^ STRING_POWER_LENGTH)
 239 +
 240 +  3)
 241 +  result     <= LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
 242 +  result + 1 >  LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
 243 +
 244 +  4) STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) - 1 < result <= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
 245 +
 246 +  MINIMUM_BASE= 2 always, LOG(MINIMUM_BASE,10)= 3.3219280948873626, result= (int)3.3219280948873626 * STRING_POWER_LENGTH
 247 +
 248 +  Last counter always use for time overflow
 249 +*/
 250 +#define POSITIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_POSITIVE_POWER_LENGTH))
 251 +#define NEGATIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_NEGATIVE_POWER_LENGTH))
 252 +#define OVERALL_POWER_COUNT (NEGATIVE_POWER_COUNT + 1 + POSITIVE_POWER_COUNT)
 253 +
 254 +#define MILLION ((unsigned long)1000 * 1000)
 255 +
 256 +namespace query_response_time
 257 +{
 258 +
 259 +class utility
 260 +{
 261 +public:
 262 +  utility() : m_base(0)
 263 +  {
 264 +    m_max_dec_value= MILLION;
 265 +    for(int i= 0; TIME_STRING_POSITIVE_POWER_LENGTH > i; ++i)
 266 +      m_max_dec_value *= 10;
 267 +    setup(DEFAULT_BASE);
 268 +  }
 269 +public:
 270 +  uint      base()            const { return m_base; }
 271 +  uint      negative_count()  const { return m_negative_count; }
 272 +  uint      positive_count()  const { return m_positive_count; }
 273 +  uint      bound_count()     const { return m_bound_count; }
 274 +  ulonglong max_dec_value()   const { return m_max_dec_value; }
 275 +  ulonglong bound(uint index) const { return m_bound[ index ]; }
 276 +public:
 277 +  void setup(uint base)
 278 +  {
 279 +    if(base != m_base)
 280 +    {
 281 +      m_base= base;
 282 +
 283 +      const ulonglong million= 1000 * 1000;
 284 +      ulonglong value= million;
 285 +      m_negative_count= 0;
 286 +      while(value > 0)
 287 +      {
 288 +       m_negative_count += 1;
 289 +       value /= m_base;
 290 +      }
 291 +      m_negative_count -= 1;
 292 +
 293 +      value= million;
 294 +      m_positive_count= 0;
 295 +      while(value < m_max_dec_value)
 296 +      {
 297 +       m_positive_count += 1;
 298 +       value *= m_base;
 299 +      }
 300 +      m_bound_count= m_negative_count + m_positive_count;
 301 +
 302 +      value= million;
 303 +      for(uint i= 0; i < m_negative_count; ++i)
 304 +      {
 305 +       value /= m_base;
 306 +       m_bound[m_negative_count - i - 1]= value;
 307 +      }
 308 +      value= million;
 309 +      for(uint i= 0; i < m_positive_count;  ++i)
 310 +      {
 311 +       m_bound[m_negative_count + i]= value;
 312 +       value *= m_base;
 313 +      }
 314 +    }
 315 +  }
 316 +private:
 317 +  uint      m_base;
 318 +  uint      m_negative_count;
 319 +  uint      m_positive_count;
 320 +  uint      m_bound_count;
 321 +  ulonglong m_max_dec_value; /* for TIME_STRING_POSITIVE_POWER_LENGTH=7 is 10000000 */
 322 +  ulonglong m_bound[OVERALL_POWER_COUNT];
 323 +};
 324 +
 325 +void print_time(char* buffer, std::size_t buffer_size, std::size_t string_positive_power_length, const char* format, uint64 value)
 326 +{
 327 +  memset(buffer,'X',buffer_size);
 328 +  buffer[string_positive_power_length]= '.';
 329 +  ulonglong second=      (value / MILLION);
 330 +  ulonglong microsecond= (value % MILLION);
 331 +  std::size_t result_length= snprintf(buffer,buffer_size,format,second,microsecond);
 332 +  if(result_length < 0)
 333 +  {
 334 +    assert(sizeof(STRING_OVERFLOW) <= buffer_size);
 335 +    memcpy(buffer, STRING_OVERFLOW, sizeof(STRING_OVERFLOW));
 336 +    return;
 337 +  }
 338 +  buffer[result_length]= 0;
 339 +}
 340 +#ifdef __x86_64__
 341 +typedef uint64 TimeCounter;
 342 +void add_time_atomic(TimeCounter* counter, uint64 time)
 343 +{
 344 +  __sync_fetch_and_add(counter,time);
 345 +}
 346 +#endif // __x86_64__
 347 +#ifdef __i386__
 348 +inline uint32 get_high(uint64 value)
 349 +{
 350 +  return ((value >> 32) << 32);
 351 +}
 352 +inline uint32 get_low(uint64 value)
 353 +{
 354 +  return ((value << 32) >> 32);
 355 +}
 356 +#ifdef __FreeBSD__
 357 +inline bool compare_and_swap(volatile uint32 *target, uint32 old, uint32 new_value)
 358 +{
 359 +  return atomic_cmpset_32(target,old,new_value);
 360 +}
 361 +#else // __FreeBSD__
 362 +inline bool compare_and_swap(volatile uint32* target, uint32 old, uint32 new_value)
 363 +{
 364 +  return __sync_bool_compare_and_swap(target,old,new_value);
 365 +}
 366 +#endif // __FreeBSD__
 367 +class TimeCounter
 368 +{
 369 +public:
 370 +  TimeCounter& operator=(uint64 time)
 371 +  {
 372 +    this->m_high= get_high(time);
 373 +    this->m_low=  get_low(time);
 374 +    return *this;
 375 +  }
 376 +  operator uint64() const
 377 +  {
 378 +    return ((static_cast<uint64>(m_high) << 32) + static_cast<uint64>(m_low));
 379 +  }
 380 +  void add(uint64 time)
 381 +  {
 382 +    uint32 time_high = get_high(time);
 383 +    uint32 time_low  = get_low(time);
 384 +    uint64 time_low64= time_low;
 385 +    while(true)
 386 +    {
 387 +      uint32 old_low= this->m_low;
 388 +      uint64 old_low64= old_low;
 389 +
 390 +      uint64 new_low64= old_low64 + time_low64;
 391 +      uint32 new_low= (get_low(new_low64));
 392 +      bool add_high= (get_high(new_low64) != 0);
 393 +
 394 +      if(!compare_and_swap(&m_low,old_low,new_low))
 395 +      {
 396 +       continue;
 397 +      }
 398 +      if(add_high)
 399 +      {
 400 +       ++time_high;
 401 +      }
 402 +      if(time_high > 0)
 403 +      {
 404 +        __sync_fetch_and_add(&m_high,time_high);
 405 +      }
 406 +      break;
 407 +    }
 408 +  }
 409 +private:
 410 +  uint32 m_low;
 411 +  uint32 m_high;
 412 +};
 413 +void add_time_atomic(TimeCounter* counter, uint64 time)
 414 +{
 415 +  counter->add(time);
 416 +}
 417 +#endif // __i386__
 418 +
 419 +class time_collector
 420 +{
 421 +public:
 422 +  time_collector(utility& u) : m_utility(&u)
 423 +  {
 424 +  }
 425 +  uint32 count(uint index) const { return m_count[index]; }
 426 +  uint64 total(uint index) const { return m_total[index]; }
 427 +public:
 428 +  void flush()
 429 +  {
 430 +    memset(&m_count,0,sizeof(m_count));
 431 +    memset((void*)&m_total,0,sizeof(m_total));
 432 +  }
 433 +  void collect(uint64 time)
 434 +  {
 435 +    bool no_collect= false;
 436 +    DBUG_EXECUTE_IF("response_time_distribution_log_only_more_300_milliseconds", {   \
 437 +        no_collect= time < 300 * 1000; \
 438 +      });
 439 +    if(no_collect) return;
 440 +    int i= 0;
 441 +    for(int count= m_utility->bound_count(); count > i; ++i)
 442 +    {
 443 +      if(m_utility->bound(i) > time)
 444 +      {
 445 +        __sync_fetch_and_add(&(m_count[i]),(uint32)1);
 446 +        add_time_atomic(&(m_total[i]),time);
 447 +        break;
 448 +      }
 449 +    }
 450 +  }
 451 +private:
 452 +  utility* m_utility;
 453 +  uint32   m_count[OVERALL_POWER_COUNT + 1];
 454 +  TimeCounter m_total[OVERALL_POWER_COUNT + 1];
 455 +};
 456 +
 457 +class collector
 458 +{
 459 +public:
 460 +  collector() : m_time(m_utility)
 461 +  {
 462 +    m_utility.setup(DEFAULT_BASE);
 463 +    m_time.flush();
 464 +  }
 465 +public:
 466 +  void flush()
 467 +  {
 468 +    m_utility.setup(opt_query_response_time_range_base);
 469 +    m_time.flush();
 470 +  }
 471 +  int fill(THD* thd, TABLE_LIST *tables, COND *cond)
 472 +  {
 473 +    DBUG_ENTER("fill_schema_query_response_time");
 474 +    TABLE        *table= static_cast<TABLE*>(tables->table);
 475 +    Field        **fields= table->field;
 476 +    for(uint i= 0, count= bound_count() + 1 /* with overflow */; count > i; ++i)
 477 +    {
 478 +      char time[TIME_STRING_BUFFER_LENGTH];
 479 +      char total[TOTAL_STRING_BUFFER_LENGTH];
 480 +      if(i == bound_count())
 481 +      {
 482 +        assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH);
 483 +        assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH);
 484 +        memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
 485 +        memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
 486 +      }
 487 +      else
 488 +      {
 489 +        print_time(time,sizeof(time),TIME_STRING_POSITIVE_POWER_LENGTH,TIME_STRING_FORMAT,this->bound(i));
 490 +        print_time(total,sizeof(total),TOTAL_STRING_POSITIVE_POWER_LENGTH,TOTAL_STRING_FORMAT,this->total(i));
 491 +      }
 492 +      fields[0]->store(time,strlen(time),system_charset_info);
 493 +      fields[1]->store(this->count(i));
 494 +      fields[2]->store(total,strlen(total),system_charset_info);
 495 +      if (schema_table_store_record(thd, table))
 496 +      {
 497 +       DBUG_RETURN(1);
 498 +      }
 499 +    }
 500 +    DBUG_RETURN(0);
 501 +  }
 502 +  void collect(ulonglong time)
 503 +  {
 504 +    m_time.collect(time);
 505 +  }
 506 +  uint bound_count() const
 507 +  {
 508 +    return m_utility.bound_count();
 509 +  }
 510 +  ulonglong bound(uint index)
 511 +  {
 512 +    return m_utility.bound(index);
 513 +  }
 514 +  ulonglong count(uint index)
 515 +  {
 516 +    return m_time.count(index);
 517 +  }
 518 +  ulonglong total(uint index)
 519 +  {
 520 +    return m_time.total(index);
 521 +  }
 522 +private:
 523 +  utility          m_utility;
 524 +  time_collector   m_time;
 525 +};
 526 +
 527 +static collector g_collector;
 528 +
 529 +} // namespace query_response_time
 530 +
 531 +void query_response_time_init()
 532 +{
 533 +}
 534 +
 535 +void query_response_time_free()
 536 +{
 537 +  query_response_time::g_collector.flush();
 538 +}
 539 +
 540 +void query_response_time_flush()
 541 +{
 542 +  query_response_time::g_collector.flush();
 543 +}
 544 +void query_response_time_collect(ulonglong query_time)
 545 +{
 546 +  query_response_time::g_collector.collect(query_time);
 547 +}
 548 +
 549 +int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
 550 +{
 551 +  return query_response_time::g_collector.fill(thd,tables,cond);
 552 +}
 553 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 554 diff -ruN a/sql/query_response_time.h b/sql/query_response_time.h
 555 --- a/sql/query_response_time.h 1970-01-01 03:00:00.000000000 +0300
 556 +++ b/sql/query_response_time.h 2011-01-17 02:13:34.000000000 +0300
 557 @@ -0,0 +1,71 @@
 558 +#ifndef QUERY_RESPONSE_TIME_H
 559 +#define QUERY_RESPONSE_TIME_H
 560 +
 561 +/*
 562 +  Settings for query response time
 563 +*/
 564 +
 565 +/*
 566 +  Maximum string length for (10 ^ (-1 * QRT_STRING_NEGATIVE_POWER_LENGTH)) in text representation.
 567 +  Example: for 6 is 0.000001
 568 +  Always 2
 569 +
 570 +  Maximum string length for (10 ^ (QRT_STRING_POSITIVE_POWER_LENGTH + 1) - 1) in text representation.
 571 +  Example: for 7 is 9999999.0
 572 +*/
 573 +#define QRT_TIME_STRING_POSITIVE_POWER_LENGTH 7
 574 +#define QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH 7
 575 +
 576 +/*
 577 +  Minimum base for log - ALWAYS 2
 578 +  Maximum base for log:
 579 +*/
 580 +#define QRT_MAXIMUM_BASE 1000
 581 +
 582 +/*
 583 +  Filler for whole number (positive power)
 584 +  Example: for
 585 +  QRT_POSITIVE_POWER_FILLER ' '
 586 +  QRT_POSITIVE_POWER_LENGTH 7
 587 +  and number 7234 result is:
 588 +  '   7234'
 589 +*/
 590 +#define QRT_POSITIVE_POWER_FILLER " "
 591 +/*
 592 +  Filler for fractional number. Similiary to whole number
 593 +*/
 594 +#define QRT_NEGATIVE_POWER_FILLER "0"
 595 +
 596 +/*
 597 +  Message if string overflow (string overflow - internal error, this string say about bug in QRT)
 598 +*/
 599 +#define QRT_STRING_OVERFLOW "TOO BIG STRING"
 600 +
 601 +/*
 602 +  Message if time too big for statistic collecting (very long query)
 603 +*/
 604 +#define QRT_TIME_OVERFLOW "TOO LONG"
 605 +
 606 +#define QRT_DEFAULT_BASE 10
 607 +
 608 +#define QRT_TIME_STRING_LENGTH                         \
 609 +  max( (QRT_TIME_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TIME_STRING_NEGATIVE_POWER_LENGTH*/), \
 610 +       max( (sizeof(QRT_TIME_OVERFLOW) - 1),           \
 611 +           (sizeof(QRT_STRING_OVERFLOW) - 1) ) )
 612 +
 613 +#define QRT_TOTAL_STRING_LENGTH                                \
 614 +  max( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \
 615 +       max( (sizeof(QRT_TIME_OVERFLOW) - 1),           \
 616 +           (sizeof(QRT_STRING_OVERFLOW) - 1) ) )
 617 +
 618 +extern ST_SCHEMA_TABLE query_response_time_table;
 619 +
 620 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 621 +extern void query_response_time_init   ();
 622 +extern void query_response_time_free   ();
 623 +extern void query_response_time_flush  ();
 624 +extern void query_response_time_collect(ulonglong query_time);
 625 +extern int  query_response_time_fill   (THD* thd, TABLE_LIST *tables, COND *cond);
 626 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 627 +
 628 +#endif // QUERY_RESPONSE_TIME_H
 629 diff -ruN a/sql/set_var.h b/sql/set_var.h
 630 --- a/sql/set_var.h     2010-12-03 20:58:26.000000000 +0300
 631 +++ b/sql/set_var.h     2011-01-17 02:20:59.000000000 +0300
 632 @@ -293,6 +293,7 @@
 633
 634  extern SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen;
 635  extern SHOW_COMP_OPTION have_query_cache;
 636 +extern SHOW_COMP_OPTION have_response_time_distribution;
 637  extern SHOW_COMP_OPTION have_geometry, have_rtree_keys;
 638  extern SHOW_COMP_OPTION have_crypt;
 639  extern SHOW_COMP_OPTION have_compress;
 640 diff -ruN a/sql/sql_parse.cc b/sql/sql_parse.cc
 641 --- a/sql/sql_parse.cc  2011-01-16 18:53:35.000000000 +0300
 642 +++ b/sql/sql_parse.cc  2011-01-17 02:15:09.000000000 +0300
 643 @@ -88,6 +88,7 @@
 644  #include "sp_cache.h"
 645  #include "events.h"
 646  #include "sql_trigger.h"
 647 +#include "query_response_time.h"
 648  #include "transaction.h"
 649  #include "sql_audit.h"
 650  #include "sql_prepare.h"
 651 @@ -1483,22 +1484,36 @@
 652      Do not log administrative statements unless the appropriate option is
 653      set.
 654    */
 655 +  #ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 656 +  if (opt_query_response_time_stats || thd->enable_slow_log)
 657 +#else // HAVE_RESPONSE_TIME_DISTRIBUTION
 658    if (thd->enable_slow_log)
 659 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 660    {
 661 -    ulonglong end_utime_of_query= thd->current_utime();
 662 -    thd_proc_info(thd, "logging slow query");
 663 -
 664 -    if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
 665 -         ((thd->server_status &
 666 -           (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
 667 -          opt_log_queries_not_using_indexes &&
 668 -           !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) &&
 669 -        thd->examined_row_count >= thd->variables.min_examined_row_limit)
 670 +    ulonglong end_utime_of_query   = thd->current_utime();
 671 +    ulonglong query_execution_time = end_utime_of_query - thd->utime_after_lock;
 672 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 673 +    if(opt_query_response_time_stats)
 674 +    {
 675 +      query_response_time_collect(query_execution_time);
 676 +    }
 677 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 678 +    if (thd->enable_slow_log)
 679      {
 680        thd_proc_info(thd, "logging slow query");
 681 -      thd->status_var.long_query_count++;
 682 -      slow_log_print(thd, thd->query(), thd->query_length(),
 683 -                     end_utime_of_query);
 684 +
 685 +      if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
 686 +           ((thd->server_status &
 687 +             (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
 688 +            opt_log_queries_not_using_indexes &&
 689 +             !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) &&
 690 +          thd->examined_row_count >= thd->variables.min_examined_row_limit)
 691 +      {
 692 +        thd_proc_info(thd, "logging slow query");
 693 +        thd->status_var.long_query_count++;
 694 +        slow_log_print(thd, thd->query(), thd->query_length(),
 695 +                       end_utime_of_query);
 696 +      }
 697      }
 698    }
 699    DBUG_VOID_RETURN;
 700 @@ -1617,6 +1632,7 @@
 701    case SCH_CHARSETS:
 702    case SCH_ENGINES:
 703    case SCH_COLLATIONS:
 704 +  case SCH_QUERY_RESPONSE_TIME:
 705    case SCH_COLLATION_CHARACTER_SET_APPLICABILITY:
 706    case SCH_USER_PRIVILEGES:
 707    case SCH_SCHEMA_PRIVILEGES:
 708 diff -ruN a/sql/sql_reload.cc b/sql/sql_reload.cc
 709 --- a/sql/sql_reload.cc 2010-12-03 20:58:26.000000000 +0300
 710 +++ b/sql/sql_reload.cc 2011-01-17 02:16:19.000000000 +0300
 711 @@ -25,7 +25,7 @@
 712  #include "hostname.h"    // hostname_cache_refresh
 713  #include "sql_repl.h"    // reset_master, reset_slave
 714  #include "debug_sync.h"
 715 -
 716 +#include "query_response_time.h"
 717
 718  /**
 719    Reload/resets privileges and the different caches.
 720 @@ -282,6 +282,12 @@
 721  #endif
 722   if (options & REFRESH_USER_RESOURCES)
 723     reset_mqh((LEX_USER *) NULL, 0);             /* purecov: inspected */
 724 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 725 + if (options & REFRESH_QUERY_RESPONSE_TIME)
 726 + {
 727 +   query_response_time_flush();
 728 + }
 729 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 730   if (*write_to_binlog != -1)
 731     *write_to_binlog= tmp_write_to_binlog;
 732   /*
 733 diff -ruN a/sql/sql_show.cc b/sql/sql_show.cc
 734 --- a/sql/sql_show.cc   2011-01-16 18:53:35.000000000 +0300
 735 +++ b/sql/sql_show.cc   2011-01-17 02:17:44.000000000 +0300
 736 @@ -50,6 +50,7 @@
 737  #include "event_data_objects.h"
 738  #endif
 739  #include <my_dir.h>
 740 +#include "query_response_time.h"
 741  #include "lock.h"                           // MYSQL_OPEN_IGNORE_FLUSH
 742  #include "debug_sync.h"
 743  #include "datadict.h"   // dd_frm_type()
 744 @@ -7688,6 +7689,14 @@
 745
 746  */
 747
 748 +ST_FIELD_INFO query_response_time_fields_info[] =
 749 +  {
 750 +    {"time",  QRT_TIME_STRING_LENGTH,      MYSQL_TYPE_STRING,  0, 0,            "", SKIP_OPEN_TABLE },
 751 +    {"count", MY_INT32_NUM_DECIMAL_DIGITS, MYSQL_TYPE_LONG, 0, MY_I_S_UNSIGNED, "", SKIP_OPEN_TABLE },
 752 +    {"total",  QRT_TIME_STRING_LENGTH,     MYSQL_TYPE_STRING,  0, 0,            "", SKIP_OPEN_TABLE },
 753 +    {0,       0,                           MYSQL_TYPE_STRING,  0, 0,             0, SKIP_OPEN_TABLE }
 754 +  };
 755 +
 756  ST_SCHEMA_TABLE schema_tables[]=
 757  {
 758    {"CHARACTER_SETS", charsets_fields_info, create_schema_table,
 759 @@ -7741,6 +7750,13 @@
 760     1, 9, 0, OPTIMIZE_I_S_TABLE|OPEN_TABLE_ONLY},
 761    {"ROUTINES", proc_fields_info, create_schema_table,
 762     fill_schema_proc, make_proc_old_format, 0, -1, -1, 0, 0},
 763 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 764 +  {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table,
 765 +   query_response_time_fill, make_old_format, 0, -1, -1, 0, 0},
 766 +#else
 767 +  {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table,
 768 +   0, make_old_format, 0, -1, -1, 0, 0},
 769 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 770    {"SCHEMATA", schema_fields_info, create_schema_table,
 771     fill_schema_schemata, make_schemata_old_format, 0, 1, -1, 0, 0},
 772    {"SCHEMA_PRIVILEGES", schema_privileges_fields_info, create_schema_table,
 773 diff -ruN a/sql/sql_yacc.yy b/sql/sql_yacc.yy
 774 --- a/sql/sql_yacc.yy   2011-01-16 18:53:34.000000000 +0300
 775 +++ b/sql/sql_yacc.yy   2011-01-17 02:19:03.000000000 +0300
 776 @@ -1193,6 +1193,7 @@
 777  %token  PURGE
 778  %token  QUARTER_SYM
 779  %token  QUERY_SYM
 780 +%token  QUERY_RESPONSE_TIME_SYM
 781  %token  QUICK
 782  %token  RANGE_SYM                     /* SQL-2003-R */
 783  %token  READS_SYM                     /* SQL-2003-R */
 784 @@ -11089,6 +11090,15 @@
 785            {
 786              Lex->sql_command = SQLCOM_SHOW_SLAVE_STAT;
 787            }
 788 +        | QUERY_RESPONSE_TIME_SYM wild_and_where
 789 +         {
 790 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 791 +           LEX *lex= Lex;
 792 +           lex->sql_command= SQLCOM_SELECT;
 793 +           if (prepare_schema_table(YYTHD, lex, 0, SCH_QUERY_RESPONSE_TIME))
 794 +             MYSQL_YYABORT;
 795 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 796 +         }
 797          | CREATE PROCEDURE_SYM sp_name
 798            {
 799              LEX *lex= Lex;
 800 @@ -11325,6 +11335,12 @@
 801            { Lex->type|= REFRESH_STATUS; }
 802          | SLAVE
 803            { Lex->type|= REFRESH_SLAVE; }
 804 +        | QUERY_RESPONSE_TIME_SYM
 805 +          {
 806 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 807 +            Lex->type|= REFRESH_QUERY_RESPONSE_TIME;
 808 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 809 +          }
 810          | MASTER_SYM
 811            { Lex->type|= REFRESH_MASTER; }
 812          | DES_KEY_FILE
 813 @@ -12610,6 +12626,7 @@
 814          | PROXY_SYM                {}
 815          | QUARTER_SYM              {}
 816          | QUERY_SYM                {}
 817 +        | QUERY_RESPONSE_TIME_SYM  {}
 818          | QUICK                    {}
 819          | READ_ONLY_SYM            {}
 820          | REBUILD_SYM              {}
 821 diff -ruN a/sql/sys_vars.cc b/sql/sys_vars.cc
 822 --- a/sql/sys_vars.cc   2011-01-16 18:53:35.000000000 +0300
 823 +++ b/sql/sys_vars.cc   2011-01-17 02:19:53.000000000 +0300
 824 @@ -49,6 +49,7 @@
 825  #include "../storage/perfschema/pfs_server.h"
 826  #endif /* WITH_PERFSCHEMA_STORAGE_ENGINE */
 827
 828 +#include "query_response_time.h"
 829  /*
 830    This forward declaration is needed because including sql_base.h
 831    causes further includes.  [TODO] Eliminate this forward declaration
 832 @@ -1791,6 +1792,26 @@
 833         DEFAULT(FALSE));
 834  #endif /* HAVE_QUERY_CACHE */
 835
 836 +
 837 +static Sys_var_have Sys_have_response_time_distribution(
 838 +       "have_response_time_distribution", "have_response_time_distribution",
 839 +       READ_ONLY GLOBAL_VAR(have_response_time_distribution), NO_CMD_LINE);
 840 +
 841 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 842 +static Sys_var_mybool Sys_query_response_time_stats(
 843 +       "query_response_time_stats", "Enable or disable query response time statisics collecting",
 844 +       GLOBAL_VAR(opt_query_response_time_stats), CMD_LINE(OPT_ARG),
 845 +       DEFAULT(FALSE));
 846 +
 847 +static Sys_var_ulong Sys_query_response_time_range_base(
 848 +       "query_response_time_range_base",
 849 +       "Select base of log for query_response_time ranges. WARNING: variable change affect only after flush",
 850 +       GLOBAL_VAR(opt_query_response_time_range_base),
 851 +       CMD_LINE(REQUIRED_ARG), VALID_RANGE(2, QRT_MAXIMUM_BASE),
 852 +       DEFAULT(QRT_DEFAULT_BASE),
 853 +       BLOCK_SIZE(1));
 854 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 855 +
 856  static Sys_var_mybool Sys_secure_auth(
 857         "secure_auth",
 858         "Disallow authentication for accounts that have old (pre-4.1) "