Merge lp:~vlad-lesin/percona-server/5.6-query_response_time-audit into lp:percona-server/5.6

[Vlad Lesin]

Port "query response time" feature
(http://www.percona.com/doc/percona-server/5.5/diagnostics/response_time_distribution.html)
as audit plugin. The original task description and related code is here:
https://mariadb.atlassian.net/browse/MDEV-4568 .

Testing: http://jenkins.percona.com/view/PS%205.6/job/percona-server-5.6-param/647

[Stewart Smith (stewart)]

Needs (C) header in all files, notably Percona-Server/plugin/query_response_time/query_response_time.cc is missing it.

should the patch to Percona-Server/sql/sp_instr.cc be sent upstream to MySQL?

review: Needs Fixing

[Laurynas Biveinis (laurynas-biveinis)]

    - Needs a blueprint. It should contain differences from the 5.5
      version of the feature.
    - HAVE_RESPONSE_TIME_DISTRIBUTION define is obsolete with a plugin
      now
    - opt_query_response_time_* vars should be initialized to FALSE
      instead of 0
    - Plugin variable description English needs fixing
    - TODO debug code in plugin callback
    - The tests do not actually run in our Jenkins, check the Jenkins
      log. The plugin adds a new test suite, but it's not included in
      the list of default suites. Let's add it there.
    - sp_lex_instr::get_command declaration should be made conditional
      on DBUG_OFF
    - Per Stewart's comment, there should be an upstream bug for the
      sp_instr.cc change. Also, aren't our other audit plugins
      affected by the same bug, perhaps it has been discussed already?

review: Needs Fixing

[Laurynas Biveinis (laurynas-biveinis)]

The "TODO debug code in plugin callback" comment above is comment for myself which I forgot to replace with the actual comment:

Why is this required?

+ if ((thd->lex->sql_command == SQLCOM_SET_OPTION) ||
+ (thd->lex->spname && thd->stmt_arena &&
+ ((sp_lex_instr *)thd->stmt_arena)->get_command() ==
+ SQLCOM_SET_OPTION )) {
+ t = 0;
+ }

review: Needs Fixing

[Vlad Lesin (vlad-lesin)]

http://jenkins.percona.com/view/PS%205.6/job/percona-server-5.6-param/711/

> - Needs a blueprint. It should contain differences from the 5.5
> version of the feature.

The difference can be found if we trace the callbacks for counting the statistics.

5.5:
dispatch_command()
  log_slow_statement()
    query_response_time_collect()
(COM_QUERY command and at the end of switch(command))

sp_instr_stmt::execute()
  log_slow_statement()
    query_response_time_collect()

Query_log_event::do_apply_event()
  log_slow_statement()
    query_response_time_collect()

5.6:
dispatch_command()
  mysql_audit_general(thd, MYSQL_AUDIT_GENERAL_STATUS, ... )
(COM_QUERY command and at the end of switch(command))

sp_instr_stmt::execute()
  mysql_audit_general(thd, MYSQL_AUDIT_GENERAL_STATUS, ...)

As we can see the 5.6 version does not count queries read by slave as mysql_audit_general() is invoked only when result is send to client.

The blueprint is created and the difference is described.

> - HAVE_RESPONSE_TIME_DISTRIBUTION define is obsolete with a plugin
> now
Done.

> - opt_query_response_time_* vars should be initialized to FALSE
> instead of 0
Done.

> - Plugin variable description English needs fixing
Hope done too.

> - The tests do not actually run in our Jenkins, check the Jenkins
> log. The plugin adds a new test suite, but it's not included in
> the list of default suites. Let's add it there.
Done. But I don't think this is a good idea because the sense of plugin is the ability to plug it in and out. If we add this suite to the list of default suites it will be impossible to remove this plugin from the source code without code fixing. Would not it be better to test the server with the custom set of suites (--suite mtr option)?

> - sp_lex_instr::get_command declaration should be made conditional
> on DBUG_OFF
Done.

> - Per Stewart's comment, there should be an upstream bug for the
> sp_instr.cc change. Also, aren't our other audit plugins
> affected by the same bug, perhaps it has been discussed already?
This is a philosophical question. It depends on what exactly we want to count. If we are interested in counting stored procedure statements as separate queries then this fix is necessary. If we want to treat "call some_function()" as a single query then we can omit the fix. But I think "response time distribution" feature itself requires SP instructions logging.

> Why is this required?
>
> + if ((thd->lex->sql_command == SQLCOM_SET_OPTION) ||
> + (thd->lex->spname && thd->stmt_arena &&
> + ((sp_lex_instr *)thd->stmt_arena)->get_command() ==
> + SQLCOM_SET_OPTION )) {
> + t = 0;
> + }
It is not necessary but it is quite handy to treat all 'SET' statements as statements with null execution time during debug because the result-set can be easily counted on paper and compared with the test output.

[Laurynas Biveinis (laurynas-biveinis)]

Vlad

(only replying to this bit, I will address the rest later)

> > - The tests do not actually run in our Jenkins, check the Jenkins
> > log. The plugin adds a new test suite, but it's not included in
> > the list of default suites. Let's add it there.
> Done. But I don't think this is a good idea because the sense of plugin is the
> ability to plug it in and out. If we add this suite to the list of default
> suites it will be impossible to remove this plugin from the source code
> without code fixing. Would not it be better to test the server with the
> custom set of suites (--suite mtr option)?

The problem appears to be that the tests do not know how to skip themselves in the case the plugin is not built:

cmake .. -DWITH_DEBUG=ON -DWITHOUT_QUERY_RESPONSE_TIME=ON
...
make
...
mysql-test-run --suite=query_response_time
...
query_response_time.basic [ fail ]
        Test ended at 2014-09-18 10:26:13

CURRENT_TEST: query_response_time.basic
mysqltest: At line 2: query 'SHOW CREATE TABLE INFORMATION_SCHEMA.QUERY_RESPONSE_TIME' failed: 1109: Unknown table 'query_response_time' in information_schema

The existing idiom to fix this in the server is to create include/have_plugin_foo.inc that skips the test if the plugin is not found, e.g.

if (!`select count(*) FROM INFORMATION_SCHEMA.PLUGINS WHERE PLUGIN_NAME='test_plugin_server' and PLUGIN_LIBRARY LIKE 'auth_test_plugin%'`) {
  --skip Need the plugin test_plugin_server
}

If this is done, then having query_response_time in the list of default suites will DTRT for both cases when the plugin is built and not built.

[Vlad Lesin (vlad-lesin)]

> The existing idiom to fix this in the server is to create
> include/have_plugin_foo.inc that skips the test if the plugin is not found,
> e.g.

Done.

[Laurynas Biveinis (laurynas-biveinis)]

    - have_query_response_time_plugin.inc references Example plugin, in the skip message and in the "exampledb" comment above. If it's a little effort to repush, please do, with a small local test, no need for Jenkins. Otherwise Approved.

review: Needs Fixing

[Vlad Lesin (vlad-lesin)]

> - have_query_response_time_plugin.inc references Example plugin, in the
> skip message and in the "exampledb" comment above. If it's a little effort to
> repush, please do, with a small local test, no need for Jenkins. Otherwise
> Approved.

Done.

[Laurynas Biveinis (laurynas-biveinis)]

"exampledb" comment still there :) anyway, good enough to merge

review: Approve

=== modified file 'Percona-Server/mysql-test/include/plugin.defs'
--- Percona-Server/mysql-test/include/plugin.defs	2013-01-18 04:53:12 +0000
+++ Percona-Server/mysql-test/include/plugin.defs	2013-12-17 07:03:32 +0000
@@ -45,3 +45,4 @@
 libmemcached       plugin/innodb_memcached/daemon_memcached DAEMON_MEMCACHED daemon_memcached
 innodb_engine      plugin/innodb_memcached/innodb_memcache INNODB_ENGINE
 validate_password  plugin/password_validation VALIDATE_PASSWORD validate_password
+query_response_time plugin/query_response_time PLUGIN_QUERY_RESPONSE_TIME QUERY_RESPONSE_TIME_AUDIT,QUERY_RESPONSE_TIME 

=== added directory 'Percona-Server/plugin/query_response_time'
=== added file 'Percona-Server/plugin/query_response_time/CMakeLists.txt'
--- Percona-Server/plugin/query_response_time/CMakeLists.txt	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/CMakeLists.txt	2013-12-17 07:03:32 +0000
@@ -0,0 +1,2 @@
+ADD_DEFINITIONS(-DHAVE_RESPONSE_TIME_DISTRIBUTION)
+MYSQL_ADD_PLUGIN(QUERY_RESPONSE_TIME query_response_time.cc plugin.cc)

=== added file 'Percona-Server/plugin/query_response_time/plugin.cc'
--- Percona-Server/plugin/query_response_time/plugin.cc	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/plugin.cc	2013-12-17 07:03:32 +0000
@@ -0,0 +1,170 @@
+/* Copyright (C) 2013 Percona and Sergey Vojtovich
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; version 2 of the License.
+
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+   GNU General Public License for more details.
+
+   You should have received a copy of the GNU General Public License
+   along with this program; if not, write to the Free Software
+   Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA */
+
+#define MYSQL_SERVER
+#include <sql_class.h>
+#include <table.h>
+#include <sql_show.h>
+#include <mysql/plugin_audit.h>
+#include <sp_instr.h>
+#include "query_response_time.h"
+
+
+ulong opt_query_response_time_range_base= QRT_DEFAULT_BASE;
+my_bool opt_query_response_time_stats= 0;
+static my_bool opt_query_response_time_flush= 0;
+
+
+static void query_response_time_flush_update(
+              MYSQL_THD thd __attribute__((unused)),
+              struct st_mysql_sys_var *var __attribute__((unused)),
+              void *tgt __attribute__((unused)),
+              const void *save __attribute__((unused)))
+{
+  query_response_time_flush();
+}
+
+
+static MYSQL_SYSVAR_ULONG(range_base, opt_query_response_time_range_base,
+       PLUGIN_VAR_RQCMDARG,
+       "Select base of log for query_response_time ranges. WARNING: variable "
+       "change affect only after flush",
+       NULL, NULL, QRT_DEFAULT_BASE, 2, QRT_MAXIMUM_BASE, 1);
+static MYSQL_SYSVAR_BOOL(stats, opt_query_response_time_stats,
+       PLUGIN_VAR_OPCMDARG,
+       "Enable or disable query response time statisics collecting",
+       NULL, NULL, FALSE);
+static MYSQL_SYSVAR_BOOL(flush, opt_query_response_time_flush,
+       PLUGIN_VAR_NOCMDOPT,
+       "Update of this variable flushes statistics and re-reads "
+       "query_response_time_range_base",
+       NULL, query_response_time_flush_update, FALSE);
+#ifndef DBUG_OFF
+static MYSQL_THDVAR_ULONGLONG(exec_time_debug, PLUGIN_VAR_NOCMDOPT,
+       "Pretend queries take this many microseconds. When 0 (the default) use "
+       "the actual execution time. Used only for debugging.",
+       NULL, NULL, 0, 0, LONG_TIMEOUT, 1);
+#endif
+
+
+static struct st_mysql_sys_var *query_response_time_info_vars[]=
+{
+  MYSQL_SYSVAR(range_base),
+  MYSQL_SYSVAR(stats),
+  MYSQL_SYSVAR(flush),
+#ifndef DBUG_OFF
+  MYSQL_SYSVAR(exec_time_debug),
+#endif
+  NULL
+};
+
+
+ST_FIELD_INFO query_response_time_fields_info[] =
+{
+  { "TIME",  QRT_TIME_STRING_LENGTH,      MYSQL_TYPE_STRING,  0, 0,               "", SKIP_OPEN_TABLE },
+  { "COUNT", MY_INT32_NUM_DECIMAL_DIGITS, MYSQL_TYPE_LONG,    0, MY_I_S_UNSIGNED, "", SKIP_OPEN_TABLE },
+  { "TOTAL", QRT_TIME_STRING_LENGTH,      MYSQL_TYPE_STRING,  0, 0,               "", SKIP_OPEN_TABLE },
+  { 0, 0, MYSQL_TYPE_NULL, 0, 0, 0, 0 }
+};
+
+
+static int query_response_time_info_init(void *p)
+{
+  ST_SCHEMA_TABLE *i_s_query_response_time= (ST_SCHEMA_TABLE *) p;
+  i_s_query_response_time->fields_info= query_response_time_fields_info;
+  i_s_query_response_time->fill_table= query_response_time_fill;
+  query_response_time_init();
+  return 0;
+}
+
+
+static int query_response_time_info_deinit(void *arg __attribute__((unused)))
+{
+  opt_query_response_time_stats= 0;
+  query_response_time_free();
+  return 0;
+}
+
+
+static struct st_mysql_information_schema query_response_time_info_descriptor=
+{ MYSQL_INFORMATION_SCHEMA_INTERFACE_VERSION };
+
+static void query_response_time_audit_notify(MYSQL_THD thd,
+                                             unsigned int event_class,
+                                             const void *event)
+{
+  const struct mysql_event_general *event_general=
+    (const struct mysql_event_general *) event;
+  DBUG_ASSERT(event_class == MYSQL_AUDIT_GENERAL_CLASS);
+  if (event_general->event_subclass == MYSQL_AUDIT_GENERAL_STATUS &&
+      opt_query_response_time_stats)
+  {
+#ifndef DBUG_OFF
+    if (THDVAR(thd, exec_time_debug)) {
+      ulonglong t = THDVAR(thd, exec_time_debug);
+      if ((thd->lex->sql_command == SQLCOM_SET_OPTION) ||
+          (thd->lex->spname && thd->stmt_arena &&
+              ((sp_lex_instr *)thd->stmt_arena)->get_command() ==
+              SQLCOM_SET_OPTION )) {
+          t = 0;
+       }
+      query_response_time_collect(t);
+    }
+    else
+#endif
+    query_response_time_collect(thd->utime_after_query - thd->utime_after_lock);
+  }
+}
+
+
+static struct st_mysql_audit query_response_time_audit_descriptor=
+{
+  MYSQL_AUDIT_INTERFACE_VERSION, NULL, query_response_time_audit_notify,
+  { (unsigned long) MYSQL_AUDIT_GENERAL_CLASSMASK }
+};
+
+
+mysql_declare_plugin(query_response_time)
+{
+  MYSQL_INFORMATION_SCHEMA_PLUGIN,
+  &query_response_time_info_descriptor,
+  "QUERY_RESPONSE_TIME",
+  "Percona and Sergey Vojtovich",
+  "Query Response Time Distribution INFORMATION_SCHEMA Plugin",
+  PLUGIN_LICENSE_GPL,
+  query_response_time_info_init,
+  query_response_time_info_deinit,
+  0x0100,
+  NULL,
+  query_response_time_info_vars,
+  (void *)"1.0",
+  0,
+},
+{
+  MYSQL_AUDIT_PLUGIN,
+  &query_response_time_audit_descriptor,
+  "QUERY_RESPONSE_TIME_AUDIT",
+  "Percona and Sergey Vojtovich",
+  "Query Response Time Distribution Audit Plugin",
+  PLUGIN_LICENSE_GPL,
+  NULL,
+  NULL,
+  0x0100,
+  NULL,
+  NULL,
+  (void *)"1.0",
+  0,
+}
+mysql_declare_plugin_end;

=== added file 'Percona-Server/plugin/query_response_time/query_response_time.cc'
--- Percona-Server/plugin/query_response_time/query_response_time.cc	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/query_response_time.cc	2013-12-17 07:03:32 +0000
@@ -0,0 +1,302 @@
+#include "mysql_version.h"
+#include "my_global.h"
+#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
+#include "mysql_com.h"
+#include "rpl_tblmap.h"
+#include "table.h"
+#include "field.h"
+#include "sql_show.h"
+#include "query_response_time.h"
+
+#define TIME_STRING_POSITIVE_POWER_LENGTH QRT_TIME_STRING_POSITIVE_POWER_LENGTH
+#define TIME_STRING_NEGATIVE_POWER_LENGTH 6
+#define TOTAL_STRING_POSITIVE_POWER_LENGTH QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH
+#define TOTAL_STRING_NEGATIVE_POWER_LENGTH 6
+#define MINIMUM_BASE 2
+#define MAXIMUM_BASE QRT_MAXIMUM_BASE
+#define POSITIVE_POWER_FILLER QRT_POSITIVE_POWER_FILLER
+#define NEGATIVE_POWER_FILLER QRT_NEGATIVE_POWER_FILLER
+#define TIME_OVERFLOW   QRT_TIME_OVERFLOW
+#define DEFAULT_BASE    QRT_DEFAULT_BASE
+
+#define do_xstr(s) do_str(s)
+#define do_str(s) #s
+#define do_format(filler,width) "%" filler width "lld"
+/*
+  Format strings for snprintf. Generate from:
+  POSITIVE_POWER_FILLER and TIME_STRING_POSITIVE_POWER_LENGTH
+  NEFATIVE_POWER_FILLER and TIME_STRING_NEGATIVE_POWER_LENGTH
+*/
+#define TIME_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TIME_STRING_POSITIVE_POWER_LENGTH))
+#define TIME_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TIME_STRING_NEGATIVE_POWER_LENGTH))
+#define TIME_STRING_FORMAT		      TIME_STRING_POSITIVE_POWER_FORMAT "." TIME_STRING_NEGATIVE_POWER_FORMAT
+
+#define TOTAL_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TOTAL_STRING_POSITIVE_POWER_LENGTH))
+#define TOTAL_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TOTAL_STRING_NEGATIVE_POWER_LENGTH))
+#define TOTAL_STRING_FORMAT		      TOTAL_STRING_POSITIVE_POWER_FORMAT "." TOTAL_STRING_NEGATIVE_POWER_FORMAT
+
+#define TIME_STRING_LENGTH	QRT_TIME_STRING_LENGTH
+#define TIME_STRING_BUFFER_LENGTH	(TIME_STRING_LENGTH + 1 /* '\0' */)
+
+#define TOTAL_STRING_LENGTH	QRT_TOTAL_STRING_LENGTH
+#define TOTAL_STRING_BUFFER_LENGTH	(TOTAL_STRING_LENGTH + 1 /* '\0' */)
+
+/*
+  Calculate length of "log linear"
+  1)
+  (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH) < (MINIMUM_BASE ^ (result + 1))
+
+  2)
+  (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH)
+  and
+  (MINIMUM_BASE ^ (result + 1)) > (10 ^ STRING_POWER_LENGTH)
+
+  3)
+  result     <= LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
+  result + 1 >  LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
+
+  4) STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) - 1 < result <= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
+
+  MINIMUM_BASE= 2 always, LOG(MINIMUM_BASE,10)= 3.3219280948873626, result= (int)3.3219280948873626 * STRING_POWER_LENGTH
+
+  Last counter always use for time overflow
+*/
+#define POSITIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_POSITIVE_POWER_LENGTH))
+#define NEGATIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_NEGATIVE_POWER_LENGTH))
+#define OVERALL_POWER_COUNT (NEGATIVE_POWER_COUNT + 1 + POSITIVE_POWER_COUNT)
+
+#define MILLION ((unsigned long)1000 * 1000)
+
+namespace query_response_time
+{
+
+class utility
+{
+public:
+  utility() : m_base(0)
+  {
+    m_max_dec_value= MILLION;
+    for(int i= 0; TIME_STRING_POSITIVE_POWER_LENGTH > i; ++i)
+      m_max_dec_value *= 10;
+    setup(DEFAULT_BASE);
+  }
+public:
+  uint      base()            const { return m_base; }
+  uint      negative_count()  const { return m_negative_count; }
+  uint      positive_count()  const { return m_positive_count; }
+  uint      bound_count()     const { return m_bound_count; }
+  ulonglong max_dec_value()   const { return m_max_dec_value; }
+  ulonglong bound(uint index) const { return m_bound[ index ]; }
+public:
+  void setup(uint base)
+  {
+    if(base != m_base)
+    {
+      m_base= base;
+
+      const ulonglong million= 1000 * 1000;
+      ulonglong value= million;
+      m_negative_count= 0;
+      while(value > 0)
+      {
+	m_negative_count += 1;
+	value /= m_base;
+      }
+      m_negative_count -= 1;
+
+      value= million;
+      m_positive_count= 0;
+      while(value < m_max_dec_value)
+      {
+	m_positive_count += 1;
+	value *= m_base;
+      }
+      m_bound_count= m_negative_count + m_positive_count;
+
+      value= million;
+      for(uint i= 0; i < m_negative_count; ++i)
+      {
+	value /= m_base;
+	m_bound[m_negative_count - i - 1]= value;
+      }
+      value= million;
+      for(uint i= 0; i < m_positive_count;  ++i)
+      {
+	m_bound[m_negative_count + i]= value;
+	value *= m_base;
+      }
+    }
+  }
+private:
+  uint      m_base;
+  uint      m_negative_count;
+  uint      m_positive_count;
+  uint      m_bound_count;
+  ulonglong m_max_dec_value; /* for TIME_STRING_POSITIVE_POWER_LENGTH=7 is 10000000 */
+  ulonglong m_bound[OVERALL_POWER_COUNT];
+};
+
+static
+void print_time(char* buffer, std::size_t buffer_size, const char* format,
+                uint64 value)
+{
+  ulonglong second=      (value / MILLION);
+  ulonglong microsecond= (value % MILLION);
+  my_snprintf(buffer, buffer_size, format, second, microsecond);
+}
+
+class time_collector
+{
+public:
+  time_collector(utility& u) : m_utility(&u)
+  {
+    my_atomic_rwlock_init(&time_collector_lock);
+  }
+  ~time_collector()
+  {
+    my_atomic_rwlock_destroy(&time_collector_lock);
+  }
+  uint32 count(uint index)
+  {
+    my_atomic_rwlock_rdlock(&time_collector_lock);
+    uint32 result= my_atomic_load32((int32*)&m_count[index]);
+    my_atomic_rwlock_rdunlock(&time_collector_lock);
+    return result;
+  }
+  uint64 total(uint index)
+  {
+    my_atomic_rwlock_rdlock(&time_collector_lock);
+    uint64 result= my_atomic_load64((int64*)&m_total[index]);
+    my_atomic_rwlock_rdunlock(&time_collector_lock);
+    return result;
+  }
+public:
+  void flush()
+  {
+    my_atomic_rwlock_wrlock(&time_collector_lock);
+    memset((void*)&m_count,0,sizeof(m_count));
+    memset((void*)&m_total,0,sizeof(m_total));
+    my_atomic_rwlock_wrunlock(&time_collector_lock);
+  }
+  void collect(uint64 time)
+  {
+    int i= 0;
+    for(int count= m_utility->bound_count(); count > i; ++i)
+    {
+      if(m_utility->bound(i) > time)
+      {
+        my_atomic_rwlock_wrlock(&time_collector_lock);
+        my_atomic_add32((int32*)(&m_count[i]), 1);
+        my_atomic_add64((int64*)(&m_total[i]), time);
+        my_atomic_rwlock_wrunlock(&time_collector_lock);
+        break;
+      }
+    }
+  }
+private:
+  utility* m_utility;
+  /* The lock for atomic operations on m_count and m_total.  Only actually
+  used on architectures that do not have atomic implementation of atomic
+  operations. */
+  my_atomic_rwlock_t time_collector_lock;
+  uint32   m_count[OVERALL_POWER_COUNT + 1];
+  uint64   m_total[OVERALL_POWER_COUNT + 1];
+};
+
+class collector
+{
+public:
+  collector() : m_time(m_utility)
+  {
+    m_utility.setup(DEFAULT_BASE);
+    m_time.flush();
+  }
+public:
+  void flush()
+  {
+    m_utility.setup(opt_query_response_time_range_base);
+    m_time.flush();
+  }
+  int fill(THD* thd, TABLE_LIST *tables, COND *cond)
+  {
+    DBUG_ENTER("fill_schema_query_response_time");
+    TABLE        *table= static_cast<TABLE*>(tables->table);
+    Field        **fields= table->field;
+    for(uint i= 0, count= bound_count() + 1 /* with overflow */; count > i; ++i)
+    {
+      char time[TIME_STRING_BUFFER_LENGTH];
+      char total[TOTAL_STRING_BUFFER_LENGTH];
+      if(i == bound_count())
+      {        
+        assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH);
+        assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH);
+        memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
+        memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
+      }
+      else
+      {
+        print_time(time, sizeof(time), TIME_STRING_FORMAT, this->bound(i));
+        print_time(total, sizeof(total), TOTAL_STRING_FORMAT, this->total(i));
+      }
+      fields[0]->store(time,strlen(time),system_charset_info);
+      fields[1]->store(this->count(i));
+      fields[2]->store(total,strlen(total),system_charset_info);
+      if (schema_table_store_record(thd, table))
+      {
+	DBUG_RETURN(1);
+      }
+    }
+    DBUG_RETURN(0);
+  }
+  void collect(ulonglong time)
+  {
+    m_time.collect(time);
+  }
+  uint bound_count() const
+  {
+    return m_utility.bound_count();
+  }
+  ulonglong bound(uint index)
+  {
+    return m_utility.bound(index);
+  }
+  ulonglong count(uint index)
+  {
+    return m_time.count(index);
+  }
+  ulonglong total(uint index)
+  {
+    return m_time.total(index);
+  }
+private:
+  utility          m_utility;
+  time_collector   m_time;
+};
+
+static collector g_collector;
+
+} // namespace query_response_time
+
+void query_response_time_init()
+{
+}
+
+void query_response_time_free()
+{
+  query_response_time::g_collector.flush();
+}
+
+void query_response_time_flush()
+{
+  query_response_time::g_collector.flush();
+}
+void query_response_time_collect(ulonglong query_time)
+{
+  query_response_time::g_collector.collect(query_time);
+}
+
+int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
+{
+  return query_response_time::g_collector.fill(thd,tables,cond);
+}
+#endif // HAVE_RESPONSE_TIME_DISTRIBUTION

=== added file 'Percona-Server/plugin/query_response_time/query_response_time.h'
--- Percona-Server/plugin/query_response_time/query_response_time.h	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/query_response_time.h	2013-12-17 07:03:32 +0000
@@ -0,0 +1,69 @@
+#ifndef QUERY_RESPONSE_TIME_H
+#define QUERY_RESPONSE_TIME_H
+
+/*
+  Settings for query response time
+*/
+
+/*
+  Maximum string length for (10 ^ (-1 * QRT_STRING_NEGATIVE_POWER_LENGTH)) in text representation.
+  Example: for 6 is 0.000001
+  Always 2
+
+  Maximum string length for (10 ^ (QRT_STRING_POSITIVE_POWER_LENGTH + 1) - 1) in text representation.
+  Example: for 7 is 9999999.0
+*/
+#define QRT_TIME_STRING_POSITIVE_POWER_LENGTH 7
+#define QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH 7
+
+/*
+  Minimum base for log - ALWAYS 2
+  Maximum base for log:
+*/
+#define QRT_MAXIMUM_BASE 1000
+
+/*
+  Filler for whole number (positive power)
+  Example: for
+  QRT_POSITIVE_POWER_FILLER ' '
+  QRT_POSITIVE_POWER_LENGTH 7
+  and number 7234 result is:
+  '   7234'
+*/
+#define QRT_POSITIVE_POWER_FILLER ""
+/*
+  Filler for fractional number. Similiary to whole number
+*/
+#define QRT_NEGATIVE_POWER_FILLER "0"
+
+/*
+  Message if time too big for statistic collecting (very long query)
+*/
+#define QRT_TIME_OVERFLOW "TOO LONG"
+
+#define QRT_DEFAULT_BASE 10
+
+#define QRT_TIME_STRING_LENGTH				\
+  MY_MAX( (QRT_TIME_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TIME_STRING_NEGATIVE_POWER_LENGTH*/), \
+       (sizeof(QRT_TIME_OVERFLOW) - 1) )
+
+#define QRT_TOTAL_STRING_LENGTH				\
+  MY_MAX( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \
+       (sizeof(QRT_TIME_OVERFLOW) - 1) )
+
+extern ST_SCHEMA_TABLE query_response_time_table;
+
+#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
+typedef class Item COND;
+
+extern void query_response_time_init   ();
+extern void query_response_time_free   ();
+extern void query_response_time_flush  ();
+extern void query_response_time_collect(ulonglong query_time);
+extern int  query_response_time_fill   (THD* thd, TABLE_LIST *tables, COND *cond);
+
+extern ulong   opt_query_response_time_range_base;
+extern my_bool opt_query_response_time_stats;
+#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
+
+#endif // QUERY_RESPONSE_TIME_H

=== added directory 'Percona-Server/plugin/query_response_time/tests'
=== added directory 'Percona-Server/plugin/query_response_time/tests/mtr'
=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/basic.result'
--- Percona-Server/plugin/query_response_time/tests/mtr/basic.result	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/basic.result	2013-12-17 07:03:32 +0000
@@ -0,0 +1,25 @@
+SHOW VARIABLES WHERE VARIABLE_NAME LIKE 'query_response_time%' AND VARIABLE_NAME!='query_response_time_exec_time_debug';
+Variable_name	Value
+query_response_time_flush	OFF
+query_response_time_range_base	10
+query_response_time_stats	OFF
+SHOW CREATE TABLE INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+Table	Create Table
+QUERY_RESPONSE_TIME	CREATE TEMPORARY TABLE `QUERY_RESPONSE_TIME` (
+  `TIME` varchar(14) NOT NULL DEFAULT '',
+  `COUNT` int(11) unsigned NOT NULL DEFAULT '0',
+  `TOTAL` varchar(14) NOT NULL DEFAULT ''
+) ENGINE=MEMORY DEFAULT CHARSET=utf8
+SELECT PLUGIN_NAME, PLUGIN_VERSION, PLUGIN_TYPE, PLUGIN_AUTHOR, PLUGIN_DESCRIPTION, PLUGIN_LICENSE FROM INFORMATION_SCHEMA.PLUGINS WHERE PLUGIN_NAME LIKE 'query_response_time%';;
+PLUGIN_NAME	QUERY_RESPONSE_TIME_AUDIT
+PLUGIN_VERSION	1.0
+PLUGIN_TYPE	AUDIT
+PLUGIN_AUTHOR	Percona and Sergey Vojtovich
+PLUGIN_DESCRIPTION	Query Response Time Distribution Audit Plugin
+PLUGIN_LICENSE	GPL
+PLUGIN_NAME	QUERY_RESPONSE_TIME
+PLUGIN_VERSION	1.0
+PLUGIN_TYPE	INFORMATION SCHEMA
+PLUGIN_AUTHOR	Percona and Sergey Vojtovich
+PLUGIN_DESCRIPTION	Query Response Time Distribution INFORMATION_SCHEMA Plugin
+PLUGIN_LICENSE	GPL

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/basic.test'
--- Percona-Server/plugin/query_response_time/tests/mtr/basic.test	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/basic.test	2013-12-17 07:03:32 +0000
@@ -0,0 +1,3 @@
+SHOW VARIABLES WHERE VARIABLE_NAME LIKE 'query_response_time%' AND VARIABLE_NAME!='query_response_time_exec_time_debug';
+SHOW CREATE TABLE INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+--query_vertical SELECT PLUGIN_NAME, PLUGIN_VERSION, PLUGIN_TYPE, PLUGIN_AUTHOR, PLUGIN_DESCRIPTION, PLUGIN_LICENSE FROM INFORMATION_SCHEMA.PLUGINS WHERE PLUGIN_NAME LIKE 'query_response_time%';

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc'
--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc	2013-12-17 07:03:32 +0000
@@ -0,0 +1,36 @@
+SET SESSION query_response_time_exec_time_debug=100000;
+
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+EVAL SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=$base;
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+
+SET SESSION query_response_time_exec_time_debug=default;

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result'
--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result	2013-12-17 07:03:32 +0000
@@ -0,0 +1,392 @@
+CREATE TABLE t(a INT);
+CREATE PROCEDURE test_f(t INT)
+BEGIN
+SET SESSION query_response_time_exec_time_debug=t;
+INSERT INTO t VALUES(1);
+SET SESSION query_response_time_exec_time_debug=100000;
+DELETE FROM t;
+END^
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1;
+Warnings:
+Warning	1292	Truncated incorrect query_response_time_range_base value: '1'
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	2
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	45	      0.000000
+      0.000003	0	      0.000000
+      0.000007	0	      0.000000
+      0.000015	0	      0.000000
+      0.000030	0	      0.000000
+      0.000061	0	      0.000000
+      0.000122	0	      0.000000
+      0.000244	0	      0.000000
+      0.000488	0	      0.000000
+      0.000976	0	      0.000000
+      0.001953	0	      0.000000
+      0.003906	0	      0.000000
+      0.007812	0	      0.000000
+      0.015625	0	      0.000000
+      0.031250	0	      0.000000
+      0.062500	0	      0.000000
+      0.125000	44	      4.400000
+      0.250000	0	      0.000000
+      0.500000	10	      3.550000
+      1.000000	1	      0.500000
+      2.000000	5	      6.500000
+      4.000000	4	     10.000000
+      8.000000	2	      9.200000
+     16.000000	0	      0.000000
+     32.000000	0	      0.000000
+     64.000000	0	      0.000000
+    128.000000	0	      0.000000
+    256.000000	0	      0.000000
+    512.000000	0	      0.000000
+   1024.000000	0	      0.000000
+   2048.000000	0	      0.000000
+   4096.000000	0	      0.000000
+   8192.000000	0	      0.000000
+  16384.000000	0	      0.000000
+  32768.000000	0	      0.000000
+  65536.000000	0	      0.000000
+ 131072.000000	0	      0.000000
+ 262144.000000	0	      0.000000
+ 524288.000000	0	      0.000000
+1048576.000000	0	      0.000000
+2097152.000000	0	      0.000000
+4194304.000000	0	      0.000000
+8388608.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=2;
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	2
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	45	      0.000000
+      0.000003	0	      0.000000
+      0.000007	0	      0.000000
+      0.000015	0	      0.000000
+      0.000030	0	      0.000000
+      0.000061	0	      0.000000
+      0.000122	0	      0.000000
+      0.000244	0	      0.000000
+      0.000488	0	      0.000000
+      0.000976	0	      0.000000
+      0.001953	0	      0.000000
+      0.003906	0	      0.000000
+      0.007812	0	      0.000000
+      0.015625	0	      0.000000
+      0.031250	0	      0.000000
+      0.062500	0	      0.000000
+      0.125000	44	      4.400000
+      0.250000	0	      0.000000
+      0.500000	10	      3.550000
+      1.000000	1	      0.500000
+      2.000000	5	      6.500000
+      4.000000	4	     10.000000
+      8.000000	2	      9.200000
+     16.000000	0	      0.000000
+     32.000000	0	      0.000000
+     64.000000	0	      0.000000
+    128.000000	0	      0.000000
+    256.000000	0	      0.000000
+    512.000000	0	      0.000000
+   1024.000000	0	      0.000000
+   2048.000000	0	      0.000000
+   4096.000000	0	      0.000000
+   8192.000000	0	      0.000000
+  16384.000000	0	      0.000000
+  32768.000000	0	      0.000000
+  65536.000000	0	      0.000000
+ 131072.000000	0	      0.000000
+ 262144.000000	0	      0.000000
+ 524288.000000	0	      0.000000
+1048576.000000	0	      0.000000
+2097152.000000	0	      0.000000
+4194304.000000	0	      0.000000
+8388608.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=10;
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	10
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	45	      0.000000
+      0.000010	0	      0.000000
+      0.000100	0	      0.000000
+      0.001000	0	      0.000000
+      0.010000	0	      0.000000
+      0.100000	0	      0.000000
+      1.000000	55	      8.450000
+     10.000000	11	     25.700000
+    100.000000	0	      0.000000
+   1000.000000	0	      0.000000
+  10000.000000	0	      0.000000
+ 100000.000000	0	      0.000000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=7;
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	7
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	45	      0.000000
+      0.000008	0	      0.000000
+      0.000059	0	      0.000000
+      0.000416	0	      0.000000
+      0.002915	0	      0.000000
+      0.020408	0	      0.000000
+      0.142857	44	      4.400000
+      1.000000	11	      4.050000
+      7.000000	11	     25.700000
+     49.000000	0	      0.000000
+    343.000000	0	      0.000000
+   2401.000000	0	      0.000000
+  16807.000000	0	      0.000000
+ 117649.000000	0	      0.000000
+ 823543.000000	0	      0.000000
+5764801.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=156;
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	156
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000041	45	      0.000000
+      0.006410	0	      0.000000
+      1.000000	55	      8.450000
+    156.000000	11	     25.700000
+  24336.000000	0	      0.000000
+3796416.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1000;
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	1000
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	45	      0.000000
+      0.001000	0	      0.000000
+      1.000000	55	      8.450000
+   1000.000000	11	     25.700000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1001;
+Warnings:
+Warning	1292	Truncated incorrect query_response_time_range_base value: '1001'
+SET GLOBAL query_response_time_flush=1;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+CALL test_f(310000);
+CALL test_f(320000);
+CALL test_f(330000);
+CALL test_f(340000);
+CALL test_f(350000);
+CALL test_f(360000);
+CALL test_f(370000);
+CALL test_f(380000);
+CALL test_f(390000);
+CALL test_f(400000);
+CALL test_f(1100000);
+CALL test_f(1200000);
+CALL test_f(1300000);
+CALL test_f(1500000);
+CALL test_f(1400000);
+CALL test_f(500000);
+CALL test_f(2100000);
+CALL test_f(2300000);
+CALL test_f(2500000);
+CALL test_f(3100000);
+CALL test_f(4100000);
+CALL test_f(5100000);
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	1000
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	45	      0.000000
+      0.001000	0	      0.000000
+      1.000000	55	      8.450000
+   1000.000000	11	     25.700000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
+DROP PROCEDURE test_f;
+DROP TABLE t;

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test'
--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test	2013-12-17 07:03:32 +0000
@@ -0,0 +1,44 @@
+--source include/have_debug.inc
+
+# The file with expected results fits only to a run without
+# ps-protocol/sp-protocol/cursor-protocol/view-protocol.
+if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
+            + $VIEW_PROTOCOL > 0`)
+{
+   --skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
+}
+
+
+CREATE TABLE t(a INT);
+
+delimiter ^;
+CREATE PROCEDURE test_f(t INT)
+BEGIN
+  SET SESSION query_response_time_exec_time_debug=t;
+  INSERT INTO t VALUES(1);
+  SET SESSION query_response_time_exec_time_debug=100000;
+  DELETE FROM t;
+END^
+delimiter ;^
+
+--let base=1
+--source query_response_time-stored.inc
+--let base=2
+--source query_response_time-stored.inc
+--let base=10
+--source query_response_time-stored.inc
+--let base=7
+--source query_response_time-stored.inc
+--let base=156
+--source query_response_time-stored.inc
+--let base=1000
+--source query_response_time-stored.inc
+--let base=1001
+--source query_response_time-stored.inc
+
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
+
+DROP PROCEDURE test_f;
+
+DROP TABLE t;

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc'
--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc	2013-12-17 07:03:32 +0000
@@ -0,0 +1,41 @@
+SET SESSION query_response_time_exec_time_debug=100000;
+
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+EVAL SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=$base;
+SET GLOBAL query_response_time_flush=1;
+# Following two queries check works of FLUSH and 
+# respecting of "QUERY_RESPONSE_TIME_STATS" variable (see launchpad bug #855312)
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+
+SET SESSION query_response_time_exec_time_debug=310000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=320000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=330000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=340000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=350000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=360000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=370000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=380000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=390000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=400000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=1100000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=1200000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=1300000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=1500000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=1400000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=500000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=2100000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=2300000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=2500000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=3100000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=4100000; SELECT 1;
+SET SESSION query_response_time_exec_time_debug=5100000; SELECT 1;
+
+SET SESSION query_response_time_exec_time_debug=100000;
+
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+
+SET SESSION query_response_time_exec_time_debug=default;

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result'
--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result	2013-12-17 07:03:32 +0000
@@ -0,0 +1,1003 @@
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1;
+Warnings:
+Warning	1292	Truncated incorrect query_response_time_range_base value: '1'
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	0	      0.000000
+      0.000003	0	      0.000000
+      0.000007	0	      0.000000
+      0.000015	0	      0.000000
+      0.000030	0	      0.000000
+      0.000061	0	      0.000000
+      0.000122	0	      0.000000
+      0.000244	0	      0.000000
+      0.000488	0	      0.000000
+      0.000976	0	      0.000000
+      0.001953	0	      0.000000
+      0.003906	0	      0.000000
+      0.007812	0	      0.000000
+      0.015625	0	      0.000000
+      0.031250	0	      0.000000
+      0.062500	0	      0.000000
+      0.125000	0	      0.000000
+      0.250000	0	      0.000000
+      0.500000	0	      0.000000
+      1.000000	0	      0.000000
+      2.000000	0	      0.000000
+      4.000000	0	      0.000000
+      8.000000	0	      0.000000
+     16.000000	0	      0.000000
+     32.000000	0	      0.000000
+     64.000000	0	      0.000000
+    128.000000	0	      0.000000
+    256.000000	0	      0.000000
+    512.000000	0	      0.000000
+   1024.000000	0	      0.000000
+   2048.000000	0	      0.000000
+   4096.000000	0	      0.000000
+   8192.000000	0	      0.000000
+  16384.000000	0	      0.000000
+  32768.000000	0	      0.000000
+  65536.000000	0	      0.000000
+ 131072.000000	0	      0.000000
+ 262144.000000	0	      0.000000
+ 524288.000000	0	      0.000000
+1048576.000000	0	      0.000000
+2097152.000000	0	      0.000000
+4194304.000000	0	      0.000000
+8388608.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	2
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	24	      0.000000
+      0.000003	0	      0.000000
+      0.000007	0	      0.000000
+      0.000015	0	      0.000000
+      0.000030	0	      0.000000
+      0.000061	0	      0.000000
+      0.000122	0	      0.000000
+      0.000244	0	      0.000000
+      0.000488	0	      0.000000
+      0.000976	0	      0.000000
+      0.001953	0	      0.000000
+      0.003906	0	      0.000000
+      0.007812	0	      0.000000
+      0.015625	0	      0.000000
+      0.031250	0	      0.000000
+      0.062500	0	      0.000000
+      0.125000	0	      0.000000
+      0.250000	0	      0.000000
+      0.500000	10	      3.550000
+      1.000000	1	      0.500000
+      2.000000	5	      6.500000
+      4.000000	4	     10.000000
+      8.000000	2	      9.200000
+     16.000000	0	      0.000000
+     32.000000	0	      0.000000
+     64.000000	0	      0.000000
+    128.000000	0	      0.000000
+    256.000000	0	      0.000000
+    512.000000	0	      0.000000
+   1024.000000	0	      0.000000
+   2048.000000	0	      0.000000
+   4096.000000	0	      0.000000
+   8192.000000	0	      0.000000
+  16384.000000	0	      0.000000
+  32768.000000	0	      0.000000
+  65536.000000	0	      0.000000
+ 131072.000000	0	      0.000000
+ 262144.000000	0	      0.000000
+ 524288.000000	0	      0.000000
+1048576.000000	0	      0.000000
+2097152.000000	0	      0.000000
+4194304.000000	0	      0.000000
+8388608.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=2;
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	0	      0.000000
+      0.000003	0	      0.000000
+      0.000007	0	      0.000000
+      0.000015	0	      0.000000
+      0.000030	0	      0.000000
+      0.000061	0	      0.000000
+      0.000122	0	      0.000000
+      0.000244	0	      0.000000
+      0.000488	0	      0.000000
+      0.000976	0	      0.000000
+      0.001953	0	      0.000000
+      0.003906	0	      0.000000
+      0.007812	0	      0.000000
+      0.015625	0	      0.000000
+      0.031250	0	      0.000000
+      0.062500	0	      0.000000
+      0.125000	0	      0.000000
+      0.250000	0	      0.000000
+      0.500000	0	      0.000000
+      1.000000	0	      0.000000
+      2.000000	0	      0.000000
+      4.000000	0	      0.000000
+      8.000000	0	      0.000000
+     16.000000	0	      0.000000
+     32.000000	0	      0.000000
+     64.000000	0	      0.000000
+    128.000000	0	      0.000000
+    256.000000	0	      0.000000
+    512.000000	0	      0.000000
+   1024.000000	0	      0.000000
+   2048.000000	0	      0.000000
+   4096.000000	0	      0.000000
+   8192.000000	0	      0.000000
+  16384.000000	0	      0.000000
+  32768.000000	0	      0.000000
+  65536.000000	0	      0.000000
+ 131072.000000	0	      0.000000
+ 262144.000000	0	      0.000000
+ 524288.000000	0	      0.000000
+1048576.000000	0	      0.000000
+2097152.000000	0	      0.000000
+4194304.000000	0	      0.000000
+8388608.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	2
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	24	      0.000000
+      0.000003	0	      0.000000
+      0.000007	0	      0.000000
+      0.000015	0	      0.000000
+      0.000030	0	      0.000000
+      0.000061	0	      0.000000
+      0.000122	0	      0.000000
+      0.000244	0	      0.000000
+      0.000488	0	      0.000000
+      0.000976	0	      0.000000
+      0.001953	0	      0.000000
+      0.003906	0	      0.000000
+      0.007812	0	      0.000000
+      0.015625	0	      0.000000
+      0.031250	0	      0.000000
+      0.062500	0	      0.000000
+      0.125000	0	      0.000000
+      0.250000	0	      0.000000
+      0.500000	10	      3.550000
+      1.000000	1	      0.500000
+      2.000000	5	      6.500000
+      4.000000	4	     10.000000
+      8.000000	2	      9.200000
+     16.000000	0	      0.000000
+     32.000000	0	      0.000000
+     64.000000	0	      0.000000
+    128.000000	0	      0.000000
+    256.000000	0	      0.000000
+    512.000000	0	      0.000000
+   1024.000000	0	      0.000000
+   2048.000000	0	      0.000000
+   4096.000000	0	      0.000000
+   8192.000000	0	      0.000000
+  16384.000000	0	      0.000000
+  32768.000000	0	      0.000000
+  65536.000000	0	      0.000000
+ 131072.000000	0	      0.000000
+ 262144.000000	0	      0.000000
+ 524288.000000	0	      0.000000
+1048576.000000	0	      0.000000
+2097152.000000	0	      0.000000
+4194304.000000	0	      0.000000
+8388608.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=10;
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	0	      0.000000
+      0.000010	0	      0.000000
+      0.000100	0	      0.000000
+      0.001000	0	      0.000000
+      0.010000	0	      0.000000
+      0.100000	0	      0.000000
+      1.000000	0	      0.000000
+     10.000000	0	      0.000000
+    100.000000	0	      0.000000
+   1000.000000	0	      0.000000
+  10000.000000	0	      0.000000
+ 100000.000000	0	      0.000000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	10
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	24	      0.000000
+      0.000010	0	      0.000000
+      0.000100	0	      0.000000
+      0.001000	0	      0.000000
+      0.010000	0	      0.000000
+      0.100000	0	      0.000000
+      1.000000	11	      4.050000
+     10.000000	11	     25.700000
+    100.000000	0	      0.000000
+   1000.000000	0	      0.000000
+  10000.000000	0	      0.000000
+ 100000.000000	0	      0.000000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=7;
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	0	      0.000000
+      0.000008	0	      0.000000
+      0.000059	0	      0.000000
+      0.000416	0	      0.000000
+      0.002915	0	      0.000000
+      0.020408	0	      0.000000
+      0.142857	0	      0.000000
+      1.000000	0	      0.000000
+      7.000000	0	      0.000000
+     49.000000	0	      0.000000
+    343.000000	0	      0.000000
+   2401.000000	0	      0.000000
+  16807.000000	0	      0.000000
+ 117649.000000	0	      0.000000
+ 823543.000000	0	      0.000000
+5764801.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	7
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	24	      0.000000
+      0.000008	0	      0.000000
+      0.000059	0	      0.000000
+      0.000416	0	      0.000000
+      0.002915	0	      0.000000
+      0.020408	0	      0.000000
+      0.142857	0	      0.000000
+      1.000000	11	      4.050000
+      7.000000	11	     25.700000
+     49.000000	0	      0.000000
+    343.000000	0	      0.000000
+   2401.000000	0	      0.000000
+  16807.000000	0	      0.000000
+ 117649.000000	0	      0.000000
+ 823543.000000	0	      0.000000
+5764801.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=156;
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000041	0	      0.000000
+      0.006410	0	      0.000000
+      1.000000	0	      0.000000
+    156.000000	0	      0.000000
+  24336.000000	0	      0.000000
+3796416.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	156
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000041	24	      0.000000
+      0.006410	0	      0.000000
+      1.000000	11	      4.050000
+    156.000000	11	     25.700000
+  24336.000000	0	      0.000000
+3796416.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1000;
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	0	      0.000000
+      0.001000	0	      0.000000
+      1.000000	0	      0.000000
+   1000.000000	0	      0.000000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	1000
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	24	      0.000000
+      0.001000	0	      0.000000
+      1.000000	11	      4.050000
+   1000.000000	11	     25.700000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1001;
+Warnings:
+Warning	1292	Truncated incorrect query_response_time_range_base value: '1001'
+SET GLOBAL query_response_time_flush=1;
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	0	      0.000000
+      0.001000	0	      0.000000
+      1.000000	0	      0.000000
+   1000.000000	0	      0.000000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
+SET SESSION query_response_time_exec_time_debug=310000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=320000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=330000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=340000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=350000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=360000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=370000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=380000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=390000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1200000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=1400000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2300000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=2500000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=3100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=4100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=5100000;
+SELECT 1;
+1
+1
+SET SESSION query_response_time_exec_time_debug=100000;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
+Variable_name	Value
+query_response_time_range_base	1000
+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
+TIME	COUNT	TOTAL
+      0.000001	24	      0.000000
+      0.001000	0	      0.000000
+      1.000000	11	      4.050000
+   1000.000000	11	     25.700000
+1000000.000000	0	      0.000000
+TOO LONG	0	TOO LONG
+SET SESSION query_response_time_exec_time_debug=default;
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test'
--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test	2013-12-17 07:03:32 +0000
@@ -0,0 +1,28 @@
+--source include/have_debug.inc
+
+# The file with expected results fits only to a run without
+# ps-protocol/sp-protocol/cursor-protocol/view-protocol.
+if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
+            + $VIEW_PROTOCOL > 0`)
+{
+   --skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
+}
+
+
+--let base=1
+--source query_response_time.inc
+--let base=2
+--source query_response_time.inc
+--let base=10
+--source query_response_time.inc
+--let base=7
+--source query_response_time.inc
+--let base=156
+--source query_response_time.inc
+--let base=1000
+--source query_response_time.inc
+--let base=1001
+--source query_response_time.inc
+
+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/suite.opt'
--- Percona-Server/plugin/query_response_time/tests/mtr/suite.opt	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/suite.opt	2013-12-17 07:03:32 +0000
@@ -0,0 +1,1 @@
+$PLUGIN_QUERY_RESPONSE_TIME_OPT $PLUGIN_QUERY_RESPONSE_TIME_LOAD

=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/suite.pm'
--- Percona-Server/plugin/query_response_time/tests/mtr/suite.pm	1970-01-01 00:00:00 +0000
+++ Percona-Server/plugin/query_response_time/tests/mtr/suite.pm	2013-12-17 07:03:32 +0000
@@ -0,0 +1,12 @@
+package My::Suite::Query_response_time;
+
+@ISA = qw(My::Suite);
+
+return "No QUERY_RESPONSE_TIME plugin" unless
+  $ENV{QUERY_RESPONSE_TIME_SO} or
+  $::mysqld_variables{'query-response-time'} eq "ON";
+
+return "Not run for embedded server" if $::opt_embedded_server;
+
+bless { };
+

=== modified file 'Percona-Server/sql/sp_instr.cc'
--- Percona-Server/sql/sp_instr.cc	2013-12-05 17:23:10 +0000
+++ Percona-Server/sql/sp_instr.cc	2013-12-17 07:03:32 +0000
@@ -27,6 +27,7 @@
 #include "sql_parse.h"    // check_table_access
 #include "sql_prepare.h"  // reinit_stmt_before_use
 #include "transaction.h"  // trans_commit_stmt
+#include "sql_audit.h"
 
 #include <algorithm>
 
@@ -818,6 +819,11 @@
 
     query_cache_end_of_result(thd);
 
+    mysql_audit_general(thd, MYSQL_AUDIT_GENERAL_STATUS,
+                        thd->get_stmt_da()->is_error() ?
+                            thd->get_stmt_da()->sql_errno() : 0,
+                        command_name[COM_QUERY].str);
+
     if (!rc && unlikely(log_slow_applicable(thd)))
     {
       /*

=== modified file 'Percona-Server/sql/sp_instr.h'
--- Percona-Server/sql/sp_instr.h	2013-08-27 11:20:01 +0000
+++ Percona-Server/sql/sp_instr.h	2013-12-17 07:03:32 +0000
@@ -214,6 +214,10 @@
   */
   bool validate_lex_and_execute_core(THD *thd, uint *nextp, bool open_tables);
 
+  int get_command() const {
+      return m_lex ? m_lex->sql_command : -1;
+  }
+
 private:
   /**
     Prepare LEX and thread for execution of instruction, if requested open

=== modified file 'Percona-Server/sql/sql_class.h'
--- Percona-Server/sql/sql_class.h	2013-12-16 08:45:31 +0000
+++ Percona-Server/sql/sql_class.h	2013-12-17 07:03:32 +0000
@@ -2328,7 +2328,7 @@
   struct timeval user_time;
   // track down slow pthread_create
   ulonglong  prior_thr_create_utime, thr_create_utime;
-  ulonglong  start_utime, utime_after_lock;
+  ulonglong  start_utime, utime_after_lock, utime_after_query;
 
   thr_lock_type update_lock_default;
   Delayed_insert *di;
@@ -3605,8 +3605,8 @@
   */
   void update_server_status()
   {
-    ulonglong end_utime_of_query= current_utime();
-    if (end_utime_of_query > utime_after_lock + variables.long_query_time)
+    utime_after_query= current_utime();
+    if (utime_after_query > utime_after_lock + variables.long_query_time)
       server_status|= SERVER_QUERY_WAS_SLOW;
   }
   inline ulonglong found_rows(void)