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    2011-03-31 17:36:18.000000000 +0400
  10 +++ b/CMakeLists.txt    2011-04-09 19:12:12.000000000 +0400
  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       2011-03-31 17:36:18.000000000 +0400
  27 +++ b/include/mysql_com.h       2011-04-10 11:28:51.000000000 +0400
  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 /dev/null b/patch_info/response-time-distribution.info
  45 --- /dev/null   1970-01-01 00:00:00.000000000 +0000
  46 +++ b/patch_info/response-time-distribution.info        2011-04-09 19:12:12.000000000 +0400
  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        2011-03-31 17:36:18.000000000 +0400
  59 +++ b/sql/CMakeLists.txt        2011-04-09 19:12:12.000000000 +0400
  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-04-09 19:11:54.000000000 +0400
  80 +++ b/sql/handler.h     2011-04-10 11:28:51.000000000 +0400
  81 @@ -578,6 +578,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 2011-03-31 17:36:18.000000000 +0400
  91 +++ b/sql/lex.h 2011-04-10 11:28:52.000000000 +0400
  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-04-09 19:12:11.000000000 +0400
 102 +++ b/sql/mysqld.cc     2011-04-10 11:28:52.000000000 +0400
 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 @@ -610,7 +612,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 @@ -911,6 +913,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 @@ -1482,6 +1488,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 @@ -3964,6 +3973,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 @@ -6852,6 +6864,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-04-09 19:12:11.000000000 +0400
 166 +++ b/sql/mysqld.h      2011-04-10 11:28:52.000000000 +0400
 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 /dev/null b/sql/query_response_time.cc
 179 --- /dev/null   1970-01-01 00:00:00.000000000 +0000
 180 +++ b/sql/query_response_time.cc        2011-04-10 00:27:11.000000000 +0400
 181 @@ -0,0 +1,367 @@
 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 +    int i= 0;
 436 +    for(int count= m_utility->bound_count(); count > i; ++i)
 437 +    {
 438 +      if(m_utility->bound(i) > time)
 439 +      {
 440 +        __sync_fetch_and_add(&(m_count[i]),(uint32)1);
 441 +        add_time_atomic(&(m_total[i]),time);
 442 +        break;
 443 +      }
 444 +    }
 445 +  }
 446 +private:
 447 +  utility* m_utility;
 448 +  uint32   m_count[OVERALL_POWER_COUNT + 1];
 449 +  TimeCounter m_total[OVERALL_POWER_COUNT + 1];
 450 +};
 451 +
 452 +class collector
 453 +{
 454 +public:
 455 +  collector() : m_time(m_utility)
 456 +  {
 457 +    m_utility.setup(DEFAULT_BASE);
 458 +    m_time.flush();
 459 +  }
 460 +public:
 461 +  void flush()
 462 +  {
 463 +    m_utility.setup(opt_query_response_time_range_base);
 464 +    m_time.flush();
 465 +  }
 466 +  int fill(THD* thd, TABLE_LIST *tables, COND *cond)
 467 +  {
 468 +    DBUG_ENTER("fill_schema_query_response_time");
 469 +    TABLE        *table= static_cast<TABLE*>(tables->table);
 470 +    Field        **fields= table->field;
 471 +    for(uint i= 0, count= bound_count() + 1 /* with overflow */; count > i; ++i)
 472 +    {
 473 +      char time[TIME_STRING_BUFFER_LENGTH];
 474 +      char total[TOTAL_STRING_BUFFER_LENGTH];
 475 +      if(i == bound_count())
 476 +      {
 477 +        assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH);
 478 +        assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH);
 479 +        memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
 480 +        memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
 481 +      }
 482 +      else
 483 +      {
 484 +        print_time(time,sizeof(time),TIME_STRING_POSITIVE_POWER_LENGTH,TIME_STRING_FORMAT,this->bound(i));
 485 +        print_time(total,sizeof(total),TOTAL_STRING_POSITIVE_POWER_LENGTH,TOTAL_STRING_FORMAT,this->total(i));
 486 +      }
 487 +      fields[0]->store(time,strlen(time),system_charset_info);
 488 +      fields[1]->store(this->count(i));
 489 +      fields[2]->store(total,strlen(total),system_charset_info);
 490 +      if (schema_table_store_record(thd, table))
 491 +      {
 492 +       DBUG_RETURN(1);
 493 +      }
 494 +    }
 495 +    DBUG_RETURN(0);
 496 +  }
 497 +  void collect(ulonglong time)
 498 +  {
 499 +    m_time.collect(time);
 500 +  }
 501 +  uint bound_count() const
 502 +  {
 503 +    return m_utility.bound_count();
 504 +  }
 505 +  ulonglong bound(uint index)
 506 +  {
 507 +    return m_utility.bound(index);
 508 +  }
 509 +  ulonglong count(uint index)
 510 +  {
 511 +    return m_time.count(index);
 512 +  }
 513 +  ulonglong total(uint index)
 514 +  {
 515 +    return m_time.total(index);
 516 +  }
 517 +private:
 518 +  utility          m_utility;
 519 +  time_collector   m_time;
 520 +};
 521 +
 522 +static collector g_collector;
 523 +
 524 +} // namespace query_response_time
 525 +
 526 +void query_response_time_init()
 527 +{
 528 +}
 529 +
 530 +void query_response_time_free()
 531 +{
 532 +  query_response_time::g_collector.flush();
 533 +}
 534 +
 535 +void query_response_time_flush()
 536 +{
 537 +  query_response_time::g_collector.flush();
 538 +}
 539 +void query_response_time_collect(ulonglong query_time)
 540 +{
 541 +  query_response_time::g_collector.collect(query_time);
 542 +}
 543 +
 544 +int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
 545 +{
 546 +  return query_response_time::g_collector.fill(thd,tables,cond);
 547 +}
 548 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 549 diff -ruN /dev/null b/sql/query_response_time.h
 550 --- /dev/null   1970-01-01 00:00:00.000000000 +0000
 551 +++ b/sql/query_response_time.h 2011-04-09 19:12:12.000000000 +0400
 552 @@ -0,0 +1,71 @@
 553 +#ifndef QUERY_RESPONSE_TIME_H
 554 +#define QUERY_RESPONSE_TIME_H
 555 +
 556 +/*
 557 +  Settings for query response time
 558 +*/
 559 +
 560 +/*
 561 +  Maximum string length for (10 ^ (-1 * QRT_STRING_NEGATIVE_POWER_LENGTH)) in text representation.
 562 +  Example: for 6 is 0.000001
 563 +  Always 2
 564 +
 565 +  Maximum string length for (10 ^ (QRT_STRING_POSITIVE_POWER_LENGTH + 1) - 1) in text representation.
 566 +  Example: for 7 is 9999999.0
 567 +*/
 568 +#define QRT_TIME_STRING_POSITIVE_POWER_LENGTH 7
 569 +#define QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH 7
 570 +
 571 +/*
 572 +  Minimum base for log - ALWAYS 2
 573 +  Maximum base for log:
 574 +*/
 575 +#define QRT_MAXIMUM_BASE 1000
 576 +
 577 +/*
 578 +  Filler for whole number (positive power)
 579 +  Example: for
 580 +  QRT_POSITIVE_POWER_FILLER ' '
 581 +  QRT_POSITIVE_POWER_LENGTH 7
 582 +  and number 7234 result is:
 583 +  '   7234'
 584 +*/
 585 +#define QRT_POSITIVE_POWER_FILLER " "
 586 +/*
 587 +  Filler for fractional number. Similiary to whole number
 588 +*/
 589 +#define QRT_NEGATIVE_POWER_FILLER "0"
 590 +
 591 +/*
 592 +  Message if string overflow (string overflow - internal error, this string say about bug in QRT)
 593 +*/
 594 +#define QRT_STRING_OVERFLOW "TOO BIG STRING"
 595 +
 596 +/*
 597 +  Message if time too big for statistic collecting (very long query)
 598 +*/
 599 +#define QRT_TIME_OVERFLOW "TOO LONG"
 600 +
 601 +#define QRT_DEFAULT_BASE 10
 602 +
 603 +#define QRT_TIME_STRING_LENGTH                         \
 604 +  max( (QRT_TIME_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TIME_STRING_NEGATIVE_POWER_LENGTH*/), \
 605 +       max( (sizeof(QRT_TIME_OVERFLOW) - 1),           \
 606 +           (sizeof(QRT_STRING_OVERFLOW) - 1) ) )
 607 +
 608 +#define QRT_TOTAL_STRING_LENGTH                                \
 609 +  max( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \
 610 +       max( (sizeof(QRT_TIME_OVERFLOW) - 1),           \
 611 +           (sizeof(QRT_STRING_OVERFLOW) - 1) ) )
 612 +
 613 +extern ST_SCHEMA_TABLE query_response_time_table;
 614 +
 615 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 616 +extern void query_response_time_init   ();
 617 +extern void query_response_time_free   ();
 618 +extern void query_response_time_flush  ();
 619 +extern void query_response_time_collect(ulonglong query_time);
 620 +extern int  query_response_time_fill   (THD* thd, TABLE_LIST *tables, COND *cond);
 621 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 622 +
 623 +#endif // QUERY_RESPONSE_TIME_H
 624 diff -ruN a/sql/set_var.h b/sql/set_var.h
 625 --- a/sql/set_var.h     2011-03-31 17:36:18.000000000 +0400
 626 +++ b/sql/set_var.h     2011-04-09 19:12:12.000000000 +0400
 627 @@ -293,6 +293,7 @@
 628
 629  extern SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen;
 630  extern SHOW_COMP_OPTION have_query_cache;
 631 +extern SHOW_COMP_OPTION have_response_time_distribution;
 632  extern SHOW_COMP_OPTION have_geometry, have_rtree_keys;
 633  extern SHOW_COMP_OPTION have_crypt;
 634  extern SHOW_COMP_OPTION have_compress;
 635 diff -ruN a/sql/sql_parse.cc b/sql/sql_parse.cc
 636 --- a/sql/sql_parse.cc  2011-04-09 19:12:10.000000000 +0400
 637 +++ b/sql/sql_parse.cc  2011-04-10 11:28:51.000000000 +0400
 638 @@ -88,6 +88,7 @@
 639  #include "sp_cache.h"
 640  #include "events.h"
 641  #include "sql_trigger.h"
 642 +#include "query_response_time.h"
 643  #include "transaction.h"
 644  #include "sql_audit.h"
 645  #include "sql_prepare.h"
 646 @@ -1482,22 +1483,74 @@
 647      Do not log administrative statements unless the appropriate option is
 648      set.
 649    */
 650 +  #ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 651 +  if (opt_query_response_time_stats || thd->enable_slow_log)
 652 +#else // HAVE_RESPONSE_TIME_DISTRIBUTION
 653    if (thd->enable_slow_log)
 654 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 655    {
 656 -    ulonglong end_utime_of_query= thd->current_utime();
 657 -    thd_proc_info(thd, "logging slow query");
 658 +    ulonglong end_utime_of_query   = thd->current_utime();
 659 +    ulonglong query_execution_time = end_utime_of_query - thd->utime_after_lock;
 660 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 661 +
 662 +#define DBUG_TEST_QRT(t,v)                              \
 663 +      DBUG_EXECUTE_IF(t,                                \
 664 +                      {                                 \
 665 +                        query_execution_time= v;        \
 666 +                        DBUG_SET("-d,"t);               \
 667 +                      })
 668 +
 669 +    DBUG_EXECUTE_IF("query_exec_time_debug", query_execution_time= 0; );
 670 +
 671 +    DBUG_TEST_QRT("query_exec_time_0.31", 310000UL);
 672 +    DBUG_TEST_QRT("query_exec_time_0.32", 320000UL);
 673 +    DBUG_TEST_QRT("query_exec_time_0.33", 330000UL);
 674 +    DBUG_TEST_QRT("query_exec_time_0.34", 340000UL);
 675 +    DBUG_TEST_QRT("query_exec_time_0.35", 350000UL);
 676 +    DBUG_TEST_QRT("query_exec_time_0.36", 360000UL);
 677 +    DBUG_TEST_QRT("query_exec_time_0.37", 370000UL);
 678 +    DBUG_TEST_QRT("query_exec_time_0.38", 380000UL);
 679 +    DBUG_TEST_QRT("query_exec_time_0.39", 390000UL);
 680 +    DBUG_TEST_QRT("query_exec_time_0.4",  400000UL);
 681 +    DBUG_TEST_QRT("query_exec_time_0.5",  500000UL);
 682 +    DBUG_TEST_QRT("query_exec_time_1.1",  1100000UL);
 683 +    DBUG_TEST_QRT("query_exec_time_1.2",  1200000UL);
 684 +    DBUG_TEST_QRT("query_exec_time_1.3",  1300000UL);
 685 +    DBUG_TEST_QRT("query_exec_time_1.4",  1400000UL);
 686 +    DBUG_TEST_QRT("query_exec_time_1.5",  1500000UL);
 687 +    DBUG_TEST_QRT("query_exec_time_2.1",  2100000UL);
 688 +    DBUG_TEST_QRT("query_exec_time_2.3",  2300000UL);
 689 +    DBUG_TEST_QRT("query_exec_time_2.5",  2500000UL);
 690 +
 691 +    DBUG_EXECUTE_IF("query_exec_time_debug",
 692 +                    if (query_execution_time == 0)
 693 +                      opt_query_response_time_stats= 0;
 694 +                    else
 695 +                      opt_query_response_time_stats= 1;);
 696
 697 -    if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
 698 -         ((thd->server_status &
 699 -           (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
 700 -          opt_log_queries_not_using_indexes &&
 701 -           !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) &&
 702 -        thd->examined_row_count >= thd->variables.min_examined_row_limit)
 703 +#undef DBUG_TEST_QRT
 704 +
 705 +    if(opt_query_response_time_stats)
 706 +    {
 707 +      query_response_time_collect(query_execution_time);
 708 +    }
 709 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 710 +    if (thd->enable_slow_log)
 711      {
 712        thd_proc_info(thd, "logging slow query");
 713 -      thd->status_var.long_query_count++;
 714 -      slow_log_print(thd, thd->query(), thd->query_length(),
 715 -                     end_utime_of_query);
 716 +
 717 +      if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
 718 +           ((thd->server_status &
 719 +             (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
 720 +            opt_log_queries_not_using_indexes &&
 721 +             !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) &&
 722 +          thd->examined_row_count >= thd->variables.min_examined_row_limit)
 723 +      {
 724 +        thd_proc_info(thd, "logging slow query");
 725 +        thd->status_var.long_query_count++;
 726 +        slow_log_print(thd, thd->query(), thd->query_length(),
 727 +                       end_utime_of_query);
 728 +      }
 729      }
 730    }
 731    DBUG_VOID_RETURN;
 732 @@ -1616,6 +1669,7 @@
 733    case SCH_CHARSETS:
 734    case SCH_ENGINES:
 735    case SCH_COLLATIONS:
 736 +  case SCH_QUERY_RESPONSE_TIME:
 737    case SCH_COLLATION_CHARACTER_SET_APPLICABILITY:
 738    case SCH_USER_PRIVILEGES:
 739    case SCH_SCHEMA_PRIVILEGES:
 740 diff -ruN a/sql/sql_reload.cc b/sql/sql_reload.cc
 741 --- a/sql/sql_reload.cc 2011-03-31 17:36:18.000000000 +0400
 742 +++ b/sql/sql_reload.cc 2011-04-10 11:28:51.000000000 +0400
 743 @@ -25,7 +25,7 @@
 744  #include "hostname.h"    // hostname_cache_refresh
 745  #include "sql_repl.h"    // reset_master, reset_slave
 746  #include "debug_sync.h"
 747 -
 748 +#include "query_response_time.h"
 749
 750  /**
 751    Reload/resets privileges and the different caches.
 752 @@ -296,6 +296,12 @@
 753  #endif
 754   if (options & REFRESH_USER_RESOURCES)
 755     reset_mqh((LEX_USER *) NULL, 0);             /* purecov: inspected */
 756 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 757 + if (options & REFRESH_QUERY_RESPONSE_TIME)
 758 + {
 759 +   query_response_time_flush();
 760 + }
 761 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 762   if (*write_to_binlog != -1)
 763     *write_to_binlog= tmp_write_to_binlog;
 764   /*
 765 diff -ruN a/sql/sql_show.cc b/sql/sql_show.cc
 766 --- a/sql/sql_show.cc   2011-04-09 19:12:10.000000000 +0400
 767 +++ b/sql/sql_show.cc   2011-04-10 11:28:51.000000000 +0400
 768 @@ -50,6 +50,7 @@
 769  #include "event_data_objects.h"
 770  #endif
 771  #include <my_dir.h>
 772 +#include "query_response_time.h"
 773  #include "lock.h"                           // MYSQL_OPEN_IGNORE_FLUSH
 774  #include "debug_sync.h"
 775  #include "datadict.h"   // dd_frm_type()
 776 @@ -7689,6 +7690,14 @@
 777
 778  */
 779
 780 +ST_FIELD_INFO query_response_time_fields_info[] =
 781 +  {
 782 +    {"time",  QRT_TIME_STRING_LENGTH,      MYSQL_TYPE_STRING,  0, 0,            "", SKIP_OPEN_TABLE },
 783 +    {"count", MY_INT32_NUM_DECIMAL_DIGITS, MYSQL_TYPE_LONG, 0, MY_I_S_UNSIGNED, "", SKIP_OPEN_TABLE },
 784 +    {"total",  QRT_TIME_STRING_LENGTH,     MYSQL_TYPE_STRING,  0, 0,            "", SKIP_OPEN_TABLE },
 785 +    {0,       0,                           MYSQL_TYPE_STRING,  0, 0,             0, SKIP_OPEN_TABLE }
 786 +  };
 787 +
 788  ST_SCHEMA_TABLE schema_tables[]=
 789  {
 790    {"CHARACTER_SETS", charsets_fields_info, create_schema_table,
 791 @@ -7742,6 +7751,13 @@
 792     1, 9, 0, OPTIMIZE_I_S_TABLE|OPEN_TABLE_ONLY},
 793    {"ROUTINES", proc_fields_info, create_schema_table,
 794     fill_schema_proc, make_proc_old_format, 0, -1, -1, 0, 0},
 795 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 796 +  {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table,
 797 +   query_response_time_fill, make_old_format, 0, -1, -1, 0, 0},
 798 +#else
 799 +  {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table,
 800 +   0, make_old_format, 0, -1, -1, 0, 0},
 801 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 802    {"SCHEMATA", schema_fields_info, create_schema_table,
 803     fill_schema_schemata, make_schemata_old_format, 0, 1, -1, 0, 0},
 804    {"SCHEMA_PRIVILEGES", schema_privileges_fields_info, create_schema_table,
 805 diff -ruN a/sql/sql_yacc.yy b/sql/sql_yacc.yy
 806 --- a/sql/sql_yacc.yy   2011-04-09 19:11:54.000000000 +0400
 807 +++ b/sql/sql_yacc.yy   2011-04-10 11:28:52.000000000 +0400
 808 @@ -1193,6 +1193,7 @@
 809  %token  PURGE
 810  %token  QUARTER_SYM
 811  %token  QUERY_SYM
 812 +%token  QUERY_RESPONSE_TIME_SYM
 813  %token  QUICK
 814  %token  RANGE_SYM                     /* SQL-2003-R */
 815  %token  READS_SYM                     /* SQL-2003-R */
 816 @@ -11076,6 +11077,15 @@
 817            {
 818              Lex->sql_command = SQLCOM_SHOW_SLAVE_STAT;
 819            }
 820 +        | QUERY_RESPONSE_TIME_SYM wild_and_where
 821 +         {
 822 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 823 +           LEX *lex= Lex;
 824 +           lex->sql_command= SQLCOM_SELECT;
 825 +           if (prepare_schema_table(YYTHD, lex, 0, SCH_QUERY_RESPONSE_TIME))
 826 +             MYSQL_YYABORT;
 827 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 828 +         }
 829          | CREATE PROCEDURE_SYM sp_name
 830            {
 831              LEX *lex= Lex;
 832 @@ -11312,6 +11322,12 @@
 833            { Lex->type|= REFRESH_STATUS; }
 834          | SLAVE
 835            { Lex->type|= REFRESH_SLAVE; }
 836 +        | QUERY_RESPONSE_TIME_SYM
 837 +          {
 838 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 839 +            Lex->type|= REFRESH_QUERY_RESPONSE_TIME;
 840 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 841 +          }
 842          | MASTER_SYM
 843            { Lex->type|= REFRESH_MASTER; }
 844          | DES_KEY_FILE
 845 @@ -12597,6 +12613,7 @@
 846          | PROXY_SYM                {}
 847          | QUARTER_SYM              {}
 848          | QUERY_SYM                {}
 849 +        | QUERY_RESPONSE_TIME_SYM  {}
 850          | QUICK                    {}
 851          | READ_ONLY_SYM            {}
 852          | REBUILD_SYM              {}
 853 diff -ruN a/sql/sys_vars.cc b/sql/sys_vars.cc
 854 --- a/sql/sys_vars.cc   2011-04-09 19:12:11.000000000 +0400
 855 +++ b/sql/sys_vars.cc   2011-04-10 11:28:51.000000000 +0400
 856 @@ -49,6 +49,7 @@
 857  #include "../storage/perfschema/pfs_server.h"
 858  #endif /* WITH_PERFSCHEMA_STORAGE_ENGINE */
 859
 860 +#include "query_response_time.h"
 861  /*
 862    This forward declaration is needed because including sql_base.h
 863    causes further includes.  [TODO] Eliminate this forward declaration
 864 @@ -1801,6 +1802,26 @@
 865         DEFAULT(FALSE));
 866  #endif /* HAVE_QUERY_CACHE */
 867
 868 +
 869 +static Sys_var_have Sys_have_response_time_distribution(
 870 +       "have_response_time_distribution", "have_response_time_distribution",
 871 +       READ_ONLY GLOBAL_VAR(have_response_time_distribution), NO_CMD_LINE);
 872 +
 873 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 874 +static Sys_var_mybool Sys_query_response_time_stats(
 875 +       "query_response_time_stats", "Enable or disable query response time statisics collecting",
 876 +       GLOBAL_VAR(opt_query_response_time_stats), CMD_LINE(OPT_ARG),
 877 +       DEFAULT(FALSE));
 878 +
 879 +static Sys_var_ulong Sys_query_response_time_range_base(
 880 +       "query_response_time_range_base",
 881 +       "Select base of log for query_response_time ranges. WARNING: variable change affect only after flush",
 882 +       GLOBAL_VAR(opt_query_response_time_range_base),
 883 +       CMD_LINE(REQUIRED_ARG), VALID_RANGE(2, QRT_MAXIMUM_BASE),
 884 +       DEFAULT(QRT_DEFAULT_BASE),
 885 +       BLOCK_SIZE(1));
 886 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 887 +
 888  static Sys_var_mybool Sys_secure_auth(
 889         "secure_auth",
 890         "Disallow authentication for accounts that have old (pre-4.1) "