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 @@ -141,10 +141,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 @@ -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 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 @@ -606,7 +608,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 @@ -907,6 +909,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 @@ -1478,6 +1484,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 @@ -3960,6 +3969,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 @@ -6848,6 +6860,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,310 @@
 182 +#include "mysql_version.h"
 183 +#include "my_global.h"
 184 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 185 +#include "mysql_com.h"
 186 +#include "rpl_tblmap.h"
 187 +#include "table.h"
 188 +#include "field.h"
 189 +#include "sql_show.h"
 190 +#include "query_response_time.h"
 191 +
 192 +#define TIME_STRING_POSITIVE_POWER_LENGTH QRT_TIME_STRING_POSITIVE_POWER_LENGTH
 193 +#define TIME_STRING_NEGATIVE_POWER_LENGTH 6
 194 +#define TOTAL_STRING_POSITIVE_POWER_LENGTH QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH
 195 +#define TOTAL_STRING_NEGATIVE_POWER_LENGTH 6
 196 +#define MINIMUM_BASE 2
 197 +#define MAXIMUM_BASE QRT_MAXIMUM_BASE
 198 +#define POSITIVE_POWER_FILLER QRT_POSITIVE_POWER_FILLER
 199 +#define NEGATIVE_POWER_FILLER QRT_NEGATIVE_POWER_FILLER
 200 +#define STRING_OVERFLOW QRT_STRING_OVERFLOW
 201 +#define TIME_OVERFLOW   QRT_TIME_OVERFLOW
 202 +#define DEFAULT_BASE    QRT_DEFAULT_BASE
 203 +
 204 +#define do_xstr(s) do_str(s)
 205 +#define do_str(s) #s
 206 +#define do_format(filler,width) "%" filler width "lld"
 207 +/*
 208 +  Format strings for snprintf. Generate from:
 209 +  POSITIVE_POWER_FILLER and TIME_STRING_POSITIVE_POWER_LENGTH
 210 +  NEFATIVE_POWER_FILLER and TIME_STRING_NEGATIVE_POWER_LENGTH
 211 +*/
 212 +#define TIME_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TIME_STRING_POSITIVE_POWER_LENGTH))
 213 +#define TIME_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TIME_STRING_NEGATIVE_POWER_LENGTH))
 214 +#define TIME_STRING_FORMAT                   TIME_STRING_POSITIVE_POWER_FORMAT "." TIME_STRING_NEGATIVE_POWER_FORMAT
 215 +
 216 +#define TOTAL_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TOTAL_STRING_POSITIVE_POWER_LENGTH))
 217 +#define TOTAL_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TOTAL_STRING_NEGATIVE_POWER_LENGTH))
 218 +#define TOTAL_STRING_FORMAT                  TOTAL_STRING_POSITIVE_POWER_FORMAT "." TOTAL_STRING_NEGATIVE_POWER_FORMAT
 219 +
 220 +#define TIME_STRING_LENGTH     QRT_TIME_STRING_LENGTH
 221 +#define TIME_STRING_BUFFER_LENGTH      (TIME_STRING_LENGTH + 1 /* '\0' */)
 222 +
 223 +#define TOTAL_STRING_LENGTH    QRT_TOTAL_STRING_LENGTH
 224 +#define TOTAL_STRING_BUFFER_LENGTH     (TOTAL_STRING_LENGTH + 1 /* '\0' */)
 225 +
 226 +/*
 227 +  Calculate length of "log linear"
 228 +  1)
 229 +  (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH) < (MINIMUM_BASE ^ (result + 1))
 230 +
 231 +  2)
 232 +  (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH)
 233 +  and
 234 +  (MINIMUM_BASE ^ (result + 1)) > (10 ^ STRING_POWER_LENGTH)
 235 +
 236 +  3)
 237 +  result     <= LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
 238 +  result + 1 >  LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
 239 +
 240 +  4) STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) - 1 < result <= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
 241 +
 242 +  MINIMUM_BASE= 2 always, LOG(MINIMUM_BASE,10)= 3.3219280948873626, result= (int)3.3219280948873626 * STRING_POWER_LENGTH
 243 +
 244 +  Last counter always use for time overflow
 245 +*/
 246 +#define POSITIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_POSITIVE_POWER_LENGTH))
 247 +#define NEGATIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_NEGATIVE_POWER_LENGTH))
 248 +#define OVERALL_POWER_COUNT (NEGATIVE_POWER_COUNT + 1 + POSITIVE_POWER_COUNT)
 249 +
 250 +#define MILLION ((unsigned long)1000 * 1000)
 251 +
 252 +namespace query_response_time
 253 +{
 254 +
 255 +class utility
 256 +{
 257 +public:
 258 +  utility() : m_base(0)
 259 +  {
 260 +    m_max_dec_value= MILLION;
 261 +    for(int i= 0; TIME_STRING_POSITIVE_POWER_LENGTH > i; ++i)
 262 +      m_max_dec_value *= 10;
 263 +    setup(DEFAULT_BASE);
 264 +  }
 265 +public:
 266 +  uint      base()            const { return m_base; }
 267 +  uint      negative_count()  const { return m_negative_count; }
 268 +  uint      positive_count()  const { return m_positive_count; }
 269 +  uint      bound_count()     const { return m_bound_count; }
 270 +  ulonglong max_dec_value()   const { return m_max_dec_value; }
 271 +  ulonglong bound(uint index) const { return m_bound[ index ]; }
 272 +public:
 273 +  void setup(uint base)
 274 +  {
 275 +    if(base != m_base)
 276 +    {
 277 +      m_base= base;
 278 +
 279 +      const ulonglong million= 1000 * 1000;
 280 +      ulonglong value= million;
 281 +      m_negative_count= 0;
 282 +      while(value > 0)
 283 +      {
 284 +       m_negative_count += 1;
 285 +       value /= m_base;
 286 +      }
 287 +      m_negative_count -= 1;
 288 +
 289 +      value= million;
 290 +      m_positive_count= 0;
 291 +      while(value < m_max_dec_value)
 292 +      {
 293 +       m_positive_count += 1;
 294 +       value *= m_base;
 295 +      }
 296 +      m_bound_count= m_negative_count + m_positive_count;
 297 +
 298 +      value= million;
 299 +      for(uint i= 0; i < m_negative_count; ++i)
 300 +      {
 301 +       value /= m_base;
 302 +       m_bound[m_negative_count - i - 1]= value;
 303 +      }
 304 +      value= million;
 305 +      for(uint i= 0; i < m_positive_count;  ++i)
 306 +      {
 307 +       m_bound[m_negative_count + i]= value;
 308 +       value *= m_base;
 309 +      }
 310 +    }
 311 +  }
 312 +private:
 313 +  uint      m_base;
 314 +  uint      m_negative_count;
 315 +  uint      m_positive_count;
 316 +  uint      m_bound_count;
 317 +  ulonglong m_max_dec_value; /* for TIME_STRING_POSITIVE_POWER_LENGTH=7 is 10000000 */
 318 +  ulonglong m_bound[OVERALL_POWER_COUNT];
 319 +};
 320 +
 321 +void print_time(char* buffer, std::size_t buffer_size, std::size_t string_positive_power_length, const char* format, uint64 value)
 322 +{
 323 +  memset(buffer,'X',buffer_size);
 324 +  buffer[string_positive_power_length]= '.';
 325 +  ulonglong second=      (value / MILLION);
 326 +  ulonglong microsecond= (value % MILLION);
 327 +  std::size_t result_length= snprintf(buffer,buffer_size,format,second,microsecond);
 328 +  if(result_length < 0)
 329 +  {
 330 +    assert(sizeof(STRING_OVERFLOW) <= buffer_size);
 331 +    memcpy(buffer, STRING_OVERFLOW, sizeof(STRING_OVERFLOW));
 332 +    return;
 333 +  }
 334 +  buffer[result_length]= 0;
 335 +}
 336 +
 337 +class time_collector
 338 +{
 339 +public:
 340 +  time_collector(utility& u) : m_utility(&u)
 341 +  {
 342 +    my_atomic_rwlock_init(&time_collector_lock);
 343 +  }
 344 +  ~time_collector()
 345 +  {
 346 +    my_atomic_rwlock_destroy(&time_collector_lock);
 347 +  }
 348 +  uint32 count(uint index) const
 349 +  {
 350 +    my_atomic_rwlock_rdlock(&time_collector_lock);
 351 +    uint32 result= my_atomic_load32((volatile int32*)&m_count[index]);
 352 +    my_atomic_rwlock_rdunlock(&time_collector_lock);
 353 +    return result;
 354 +  }
 355 +  uint64 total(uint index) const
 356 +  {
 357 +    my_atomic_rwlock_rdlock(&time_collector_lock);
 358 +    uint64 result= my_atomic_load64((volatile int64*)&m_total[index]);
 359 +    my_atomic_rwlock_rdunlock(&time_collector_lock);
 360 +    return result;
 361 +  }
 362 +public:
 363 +  void flush()
 364 +  {
 365 +    my_atomic_rwlock_wrlock(&time_collector_lock);
 366 +    memset((void*)&m_count,0,sizeof(m_count));
 367 +    memset((void*)&m_total,0,sizeof(m_total));
 368 +    my_atomic_rwlock_wrunlock(&time_collector_lock);
 369 +  }
 370 +  void collect(uint64 time)
 371 +  {
 372 +    int i= 0;
 373 +    for(int count= m_utility->bound_count(); count > i; ++i)
 374 +    {
 375 +      if(m_utility->bound(i) > time)
 376 +      {
 377 +        my_atomic_rwlock_wrlock(&time_collector_lock);
 378 +        my_atomic_add32((volatile int32*)(&m_count[i]), 1);
 379 +        my_atomic_add64((volatile int64*)(&m_total[i]), time);
 380 +        my_atomic_rwlock_wrunlock(&time_collector_lock);
 381 +        break;
 382 +      }
 383 +    }
 384 +  }
 385 +private:
 386 +  utility* m_utility;
 387 +  /* The lock for atomic operations on m_count and m_total.  Only actually
 388 +  used on architectures that do not have atomic implementation of atomic
 389 +  operations. */
 390 +  my_atomic_rwlock_t time_collector_lock;
 391 +  volatile uint32   m_count[OVERALL_POWER_COUNT + 1];
 392 +  volatile uint64   m_total[OVERALL_POWER_COUNT + 1];
 393 +};
 394 +
 395 +class collector
 396 +{
 397 +public:
 398 +  collector() : m_time(m_utility)
 399 +  {
 400 +    m_utility.setup(DEFAULT_BASE);
 401 +    m_time.flush();
 402 +  }
 403 +public:
 404 +  void flush()
 405 +  {
 406 +    m_utility.setup(opt_query_response_time_range_base);
 407 +    m_time.flush();
 408 +  }
 409 +  int fill(THD* thd, TABLE_LIST *tables, COND *cond)
 410 +  {
 411 +    DBUG_ENTER("fill_schema_query_response_time");
 412 +    TABLE        *table= static_cast<TABLE*>(tables->table);
 413 +    Field        **fields= table->field;
 414 +    for(uint i= 0, count= bound_count() + 1 /* with overflow */; count > i; ++i)
 415 +    {
 416 +      char time[TIME_STRING_BUFFER_LENGTH];
 417 +      char total[TOTAL_STRING_BUFFER_LENGTH];
 418 +      if(i == bound_count())
 419 +      {
 420 +        assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH);
 421 +        assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH);
 422 +        memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
 423 +        memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
 424 +      }
 425 +      else
 426 +      {
 427 +        print_time(time,sizeof(time),TIME_STRING_POSITIVE_POWER_LENGTH,TIME_STRING_FORMAT,this->bound(i));
 428 +        print_time(total,sizeof(total),TOTAL_STRING_POSITIVE_POWER_LENGTH,TOTAL_STRING_FORMAT,this->total(i));
 429 +      }
 430 +      fields[0]->store(time,strlen(time),system_charset_info);
 431 +      fields[1]->store(this->count(i));
 432 +      fields[2]->store(total,strlen(total),system_charset_info);
 433 +      if (schema_table_store_record(thd, table))
 434 +      {
 435 +       DBUG_RETURN(1);
 436 +      }
 437 +    }
 438 +    DBUG_RETURN(0);
 439 +  }
 440 +  void collect(ulonglong time)
 441 +  {
 442 +    m_time.collect(time);
 443 +  }
 444 +  uint bound_count() const
 445 +  {
 446 +    return m_utility.bound_count();
 447 +  }
 448 +  ulonglong bound(uint index)
 449 +  {
 450 +    return m_utility.bound(index);
 451 +  }
 452 +  ulonglong count(uint index)
 453 +  {
 454 +    return m_time.count(index);
 455 +  }
 456 +  ulonglong total(uint index)
 457 +  {
 458 +    return m_time.total(index);
 459 +  }
 460 +private:
 461 +  utility          m_utility;
 462 +  time_collector   m_time;
 463 +};
 464 +
 465 +static collector g_collector;
 466 +
 467 +} // namespace query_response_time
 468 +
 469 +void query_response_time_init()
 470 +{
 471 +}
 472 +
 473 +void query_response_time_free()
 474 +{
 475 +  query_response_time::g_collector.flush();
 476 +}
 477 +
 478 +void query_response_time_flush()
 479 +{
 480 +  query_response_time::g_collector.flush();
 481 +}
 482 +void query_response_time_collect(ulonglong query_time)
 483 +{
 484 +  query_response_time::g_collector.collect(query_time);
 485 +}
 486 +
 487 +int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
 488 +{
 489 +  return query_response_time::g_collector.fill(thd,tables,cond);
 490 +}
 491 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 492 diff -ruN /dev/null b/sql/query_response_time.h
 493 --- /dev/null   1970-01-01 00:00:00.000000000 +0000
 494 +++ b/sql/query_response_time.h 2011-04-09 19:12:12.000000000 +0400
 495 @@ -0,0 +1,71 @@
 496 +#ifndef QUERY_RESPONSE_TIME_H
 497 +#define QUERY_RESPONSE_TIME_H
 498 +
 499 +/*
 500 +  Settings for query response time
 501 +*/
 502 +
 503 +/*
 504 +  Maximum string length for (10 ^ (-1 * QRT_STRING_NEGATIVE_POWER_LENGTH)) in text representation.
 505 +  Example: for 6 is 0.000001
 506 +  Always 2
 507 +
 508 +  Maximum string length for (10 ^ (QRT_STRING_POSITIVE_POWER_LENGTH + 1) - 1) in text representation.
 509 +  Example: for 7 is 9999999.0
 510 +*/
 511 +#define QRT_TIME_STRING_POSITIVE_POWER_LENGTH 7
 512 +#define QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH 7
 513 +
 514 +/*
 515 +  Minimum base for log - ALWAYS 2
 516 +  Maximum base for log:
 517 +*/
 518 +#define QRT_MAXIMUM_BASE 1000
 519 +
 520 +/*
 521 +  Filler for whole number (positive power)
 522 +  Example: for
 523 +  QRT_POSITIVE_POWER_FILLER ' '
 524 +  QRT_POSITIVE_POWER_LENGTH 7
 525 +  and number 7234 result is:
 526 +  '   7234'
 527 +*/
 528 +#define QRT_POSITIVE_POWER_FILLER " "
 529 +/*
 530 +  Filler for fractional number. Similiary to whole number
 531 +*/
 532 +#define QRT_NEGATIVE_POWER_FILLER "0"
 533 +
 534 +/*
 535 +  Message if string overflow (string overflow - internal error, this string say about bug in QRT)
 536 +*/
 537 +#define QRT_STRING_OVERFLOW "TOO BIG STRING"
 538 +
 539 +/*
 540 +  Message if time too big for statistic collecting (very long query)
 541 +*/
 542 +#define QRT_TIME_OVERFLOW "TOO LONG"
 543 +
 544 +#define QRT_DEFAULT_BASE 10
 545 +
 546 +#define QRT_TIME_STRING_LENGTH                         \
 547 +  max( (QRT_TIME_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TIME_STRING_NEGATIVE_POWER_LENGTH*/), \
 548 +       max( (sizeof(QRT_TIME_OVERFLOW) - 1),           \
 549 +           (sizeof(QRT_STRING_OVERFLOW) - 1) ) )
 550 +
 551 +#define QRT_TOTAL_STRING_LENGTH                                \
 552 +  max( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \
 553 +       max( (sizeof(QRT_TIME_OVERFLOW) - 1),           \
 554 +           (sizeof(QRT_STRING_OVERFLOW) - 1) ) )
 555 +
 556 +extern ST_SCHEMA_TABLE query_response_time_table;
 557 +
 558 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 559 +extern void query_response_time_init   ();
 560 +extern void query_response_time_free   ();
 561 +extern void query_response_time_flush  ();
 562 +extern void query_response_time_collect(ulonglong query_time);
 563 +extern int  query_response_time_fill   (THD* thd, TABLE_LIST *tables, COND *cond);
 564 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 565 +
 566 +#endif // QUERY_RESPONSE_TIME_H
 567 diff -ruN a/sql/set_var.h b/sql/set_var.h
 568 --- a/sql/set_var.h     2011-03-31 17:36:18.000000000 +0400
 569 +++ b/sql/set_var.h     2011-04-09 19:12:12.000000000 +0400
 570 @@ -293,6 +293,7 @@
 571
 572  extern SHOW_COMP_OPTION have_ssl, have_symlink, have_dlopen;
 573  extern SHOW_COMP_OPTION have_query_cache;
 574 +extern SHOW_COMP_OPTION have_response_time_distribution;
 575  extern SHOW_COMP_OPTION have_geometry, have_rtree_keys;
 576  extern SHOW_COMP_OPTION have_crypt;
 577  extern SHOW_COMP_OPTION have_compress;
 578 diff -ruN a/sql/sql_parse.cc b/sql/sql_parse.cc
 579 --- a/sql/sql_parse.cc  2011-04-09 19:12:10.000000000 +0400
 580 +++ b/sql/sql_parse.cc  2011-04-10 11:28:51.000000000 +0400
 581 @@ -88,6 +88,7 @@
 582  #include "sp_cache.h"
 583  #include "events.h"
 584  #include "sql_trigger.h"
 585 +#include "query_response_time.h"
 586  #include "transaction.h"
 587  #include "sql_audit.h"
 588  #include "sql_prepare.h"
 589 @@ -1482,22 +1483,74 @@
 590      Do not log administrative statements unless the appropriate option is
 591      set.
 592    */
 593 +  #ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 594 +  if (opt_query_response_time_stats || thd->enable_slow_log)
 595 +#else // HAVE_RESPONSE_TIME_DISTRIBUTION
 596    if (thd->enable_slow_log)
 597 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 598    {
 599 -    ulonglong end_utime_of_query= thd->current_utime();
 600 -    thd_proc_info(thd, "logging slow query");
 601 +    ulonglong end_utime_of_query   = thd->current_utime();
 602 +    ulonglong query_execution_time = end_utime_of_query - thd->utime_after_lock;
 603 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 604 +
 605 +#define DBUG_TEST_QRT(t,v)                              \
 606 +      DBUG_EXECUTE_IF(t,                                \
 607 +                      {                                 \
 608 +                        query_execution_time= v;        \
 609 +                        DBUG_SET("-d,"t);               \
 610 +                      })
 611 +
 612 +    DBUG_EXECUTE_IF("query_exec_time_debug", query_execution_time= 0; );
 613 +
 614 +    DBUG_TEST_QRT("query_exec_time_0.31", 310000UL);
 615 +    DBUG_TEST_QRT("query_exec_time_0.32", 320000UL);
 616 +    DBUG_TEST_QRT("query_exec_time_0.33", 330000UL);
 617 +    DBUG_TEST_QRT("query_exec_time_0.34", 340000UL);
 618 +    DBUG_TEST_QRT("query_exec_time_0.35", 350000UL);
 619 +    DBUG_TEST_QRT("query_exec_time_0.36", 360000UL);
 620 +    DBUG_TEST_QRT("query_exec_time_0.37", 370000UL);
 621 +    DBUG_TEST_QRT("query_exec_time_0.38", 380000UL);
 622 +    DBUG_TEST_QRT("query_exec_time_0.39", 390000UL);
 623 +    DBUG_TEST_QRT("query_exec_time_0.4",  400000UL);
 624 +    DBUG_TEST_QRT("query_exec_time_0.5",  500000UL);
 625 +    DBUG_TEST_QRT("query_exec_time_1.1",  1100000UL);
 626 +    DBUG_TEST_QRT("query_exec_time_1.2",  1200000UL);
 627 +    DBUG_TEST_QRT("query_exec_time_1.3",  1300000UL);
 628 +    DBUG_TEST_QRT("query_exec_time_1.4",  1400000UL);
 629 +    DBUG_TEST_QRT("query_exec_time_1.5",  1500000UL);
 630 +    DBUG_TEST_QRT("query_exec_time_2.1",  2100000UL);
 631 +    DBUG_TEST_QRT("query_exec_time_2.3",  2300000UL);
 632 +    DBUG_TEST_QRT("query_exec_time_2.5",  2500000UL);
 633 +
 634 +    DBUG_EXECUTE_IF("query_exec_time_debug",
 635 +                    if (query_execution_time == 0)
 636 +                      opt_query_response_time_stats= 0;
 637 +                    else
 638 +                      opt_query_response_time_stats= 1;);
 639
 640 -    if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
 641 -         ((thd->server_status &
 642 -           (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
 643 -          opt_log_queries_not_using_indexes &&
 644 -           !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) &&
 645 -        thd->examined_row_count >= thd->variables.min_examined_row_limit)
 646 +#undef DBUG_TEST_QRT
 647 +
 648 +    if(opt_query_response_time_stats)
 649 +    {
 650 +      query_response_time_collect(query_execution_time);
 651 +    }
 652 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 653 +    if (thd->enable_slow_log)
 654      {
 655        thd_proc_info(thd, "logging slow query");
 656 -      thd->status_var.long_query_count++;
 657 -      slow_log_print(thd, thd->query(), thd->query_length(),
 658 -                     end_utime_of_query);
 659 +
 660 +      if (((thd->server_status & SERVER_QUERY_WAS_SLOW) ||
 661 +           ((thd->server_status &
 662 +             (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
 663 +            opt_log_queries_not_using_indexes &&
 664 +             !(sql_command_flags[thd->lex->sql_command] & CF_STATUS_COMMAND))) &&
 665 +          thd->examined_row_count >= thd->variables.min_examined_row_limit)
 666 +      {
 667 +        thd_proc_info(thd, "logging slow query");
 668 +        thd->status_var.long_query_count++;
 669 +        slow_log_print(thd, thd->query(), thd->query_length(),
 670 +                       end_utime_of_query);
 671 +      }
 672      }
 673    }
 674    DBUG_VOID_RETURN;
 675 @@ -1616,6 +1669,7 @@
 676    case SCH_CHARSETS:
 677    case SCH_ENGINES:
 678    case SCH_COLLATIONS:
 679 +  case SCH_QUERY_RESPONSE_TIME:
 680    case SCH_COLLATION_CHARACTER_SET_APPLICABILITY:
 681    case SCH_USER_PRIVILEGES:
 682    case SCH_SCHEMA_PRIVILEGES:
 683 diff -ruN a/sql/sql_reload.cc b/sql/sql_reload.cc
 684 --- a/sql/sql_reload.cc 2011-03-31 17:36:18.000000000 +0400
 685 +++ b/sql/sql_reload.cc 2011-04-10 11:28:51.000000000 +0400
 686 @@ -25,7 +25,7 @@
 687  #include "hostname.h"    // hostname_cache_refresh
 688  #include "sql_repl.h"    // reset_master, reset_slave
 689  #include "debug_sync.h"
 690 -
 691 +#include "query_response_time.h"
 692
 693  /**
 694    Reload/resets privileges and the different caches.
 695 @@ -296,6 +296,12 @@
 696  #endif
 697   if (options & REFRESH_USER_RESOURCES)
 698     reset_mqh((LEX_USER *) NULL, 0);             /* purecov: inspected */
 699 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 700 + if (options & REFRESH_QUERY_RESPONSE_TIME)
 701 + {
 702 +   query_response_time_flush();
 703 + }
 704 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 705   if (*write_to_binlog != -1)
 706     *write_to_binlog= tmp_write_to_binlog;
 707   /*
 708 diff -ruN a/sql/sql_show.cc b/sql/sql_show.cc
 709 --- a/sql/sql_show.cc   2011-04-09 19:12:10.000000000 +0400
 710 +++ b/sql/sql_show.cc   2011-04-10 11:28:51.000000000 +0400
 711 @@ -50,6 +50,7 @@
 712  #include "event_data_objects.h"
 713  #endif
 714  #include <my_dir.h>
 715 +#include "query_response_time.h"
 716  #include "lock.h"                           // MYSQL_OPEN_IGNORE_FLUSH
 717  #include "debug_sync.h"
 718  #include "datadict.h"   // dd_frm_type()
 719 @@ -7830,6 +7831,14 @@
 720
 721  */
 722
 723 +ST_FIELD_INFO query_response_time_fields_info[] =
 724 +  {
 725 +    {"time",  QRT_TIME_STRING_LENGTH,      MYSQL_TYPE_STRING,  0, 0,            "", SKIP_OPEN_TABLE },
 726 +    {"count", MY_INT32_NUM_DECIMAL_DIGITS, MYSQL_TYPE_LONG, 0, MY_I_S_UNSIGNED, "", SKIP_OPEN_TABLE },
 727 +    {"total",  QRT_TIME_STRING_LENGTH,     MYSQL_TYPE_STRING,  0, 0,            "", SKIP_OPEN_TABLE },
 728 +    {0,       0,                           MYSQL_TYPE_STRING,  0, 0,             0, SKIP_OPEN_TABLE }
 729 +  };
 730 +
 731  ST_SCHEMA_TABLE schema_tables[]=
 732  {
 733    {"CHARACTER_SETS", charsets_fields_info, create_schema_table,
 734 @@ -7883,6 +7892,13 @@
 735     1, 9, 0, OPTIMIZE_I_S_TABLE|OPEN_TABLE_ONLY},
 736    {"ROUTINES", proc_fields_info, create_schema_table,
 737     fill_schema_proc, make_proc_old_format, 0, -1, -1, 0, 0},
 738 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 739 +  {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table,
 740 +   query_response_time_fill, make_old_format, 0, -1, -1, 0, 0},
 741 +#else
 742 +  {"QUERY_RESPONSE_TIME", query_response_time_fields_info, create_schema_table,
 743 +   0, make_old_format, 0, -1, -1, 0, 0},
 744 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 745    {"SCHEMATA", schema_fields_info, create_schema_table,
 746     fill_schema_schemata, make_schemata_old_format, 0, 1, -1, 0, 0},
 747    {"SCHEMA_PRIVILEGES", schema_privileges_fields_info, create_schema_table,
 748 diff -ruN a/sql/sql_yacc.yy b/sql/sql_yacc.yy
 749 --- a/sql/sql_yacc.yy   2011-04-09 19:11:54.000000000 +0400
 750 +++ b/sql/sql_yacc.yy   2011-04-10 11:28:52.000000000 +0400
 751 @@ -1193,6 +1193,7 @@
 752  %token  PURGE
 753  %token  QUARTER_SYM
 754  %token  QUERY_SYM
 755 +%token  QUERY_RESPONSE_TIME_SYM
 756  %token  QUICK
 757  %token  RANGE_SYM                     /* SQL-2003-R */
 758  %token  READS_SYM                     /* SQL-2003-R */
 759 @@ -11076,6 +11077,15 @@
 760            {
 761              Lex->sql_command = SQLCOM_SHOW_SLAVE_STAT;
 762            }
 763 +        | QUERY_RESPONSE_TIME_SYM wild_and_where
 764 +         {
 765 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 766 +           LEX *lex= Lex;
 767 +           lex->sql_command= SQLCOM_SELECT;
 768 +           if (prepare_schema_table(YYTHD, lex, 0, SCH_QUERY_RESPONSE_TIME))
 769 +             MYSQL_YYABORT;
 770 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 771 +         }
 772          | CREATE PROCEDURE_SYM sp_name
 773            {
 774              LEX *lex= Lex;
 775 @@ -11312,6 +11322,12 @@
 776            { Lex->type|= REFRESH_STATUS; }
 777          | SLAVE
 778            { Lex->type|= REFRESH_SLAVE; }
 779 +        | QUERY_RESPONSE_TIME_SYM
 780 +          {
 781 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 782 +            Lex->type|= REFRESH_QUERY_RESPONSE_TIME;
 783 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 784 +          }
 785          | MASTER_SYM
 786            { Lex->type|= REFRESH_MASTER; }
 787          | DES_KEY_FILE
 788 @@ -12597,6 +12613,7 @@
 789          | PROXY_SYM                {}
 790          | QUARTER_SYM              {}
 791          | QUERY_SYM                {}
 792 +        | QUERY_RESPONSE_TIME_SYM  {}
 793          | QUICK                    {}
 794          | READ_ONLY_SYM            {}
 795          | REBUILD_SYM              {}
 796 diff -ruN a/sql/sys_vars.cc b/sql/sys_vars.cc
 797 --- a/sql/sys_vars.cc   2011-04-09 19:12:11.000000000 +0400
 798 +++ b/sql/sys_vars.cc   2011-04-10 11:28:51.000000000 +0400
 799 @@ -49,6 +49,7 @@
 800  #include "../storage/perfschema/pfs_server.h"
 801  #endif /* WITH_PERFSCHEMA_STORAGE_ENGINE */
 802
 803 +#include "query_response_time.h"
 804  /*
 805    This forward declaration is needed because including sql_base.h
 806    causes further includes.  [TODO] Eliminate this forward declaration
 807 @@ -1837,6 +1838,26 @@
 808         DEFAULT(FALSE));
 809  #endif /* HAVE_QUERY_CACHE */
 810
 811 +
 812 +static Sys_var_have Sys_have_response_time_distribution(
 813 +       "have_response_time_distribution", "have_response_time_distribution",
 814 +       READ_ONLY GLOBAL_VAR(have_response_time_distribution), NO_CMD_LINE);
 815 +
 816 +#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
 817 +static Sys_var_mybool Sys_query_response_time_stats(
 818 +       "query_response_time_stats", "Enable or disable query response time statisics collecting",
 819 +       GLOBAL_VAR(opt_query_response_time_stats), CMD_LINE(OPT_ARG),
 820 +       DEFAULT(FALSE));
 821 +
 822 +static Sys_var_ulong Sys_query_response_time_range_base(
 823 +       "query_response_time_range_base",
 824 +       "Select base of log for query_response_time ranges. WARNING: variable change affect only after flush",
 825 +       GLOBAL_VAR(opt_query_response_time_range_base),
 826 +       CMD_LINE(REQUIRED_ARG), VALID_RANGE(2, QRT_MAXIMUM_BASE),
 827 +       DEFAULT(QRT_DEFAULT_BASE),
 828 +       BLOCK_SIZE(1));
 829 +#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
 830 +
 831  static Sys_var_mybool Sys_secure_auth(
 832         "secure_auth",
 833         "Disallow authentication for accounts that have old (pre-4.1) "