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

Proposed by Vlad Lesin on 2013-12-17
Status: Merged
Approved by: Laurynas Biveinis on 2014-09-25
Approved revision: 517
Merged at revision: 664
Proposed branch: lp:~vlad-lesin/percona-server/5.6-query_response_time-audit
Merge into: lp:percona-server/5.6
Diff against target: 2272 lines (+2142/-3)
18 files modified
Percona-Server/mysql-test/include/plugin.defs (+1/-0)
Percona-Server/plugin/query_response_time/CMakeLists.txt (+2/-0)
Percona-Server/plugin/query_response_time/plugin.cc (+170/-0)
Percona-Server/plugin/query_response_time/query_response_time.cc (+302/-0)
Percona-Server/plugin/query_response_time/query_response_time.h (+69/-0)
Percona-Server/plugin/query_response_time/tests/mtr/basic.result (+25/-0)
Percona-Server/plugin/query_response_time/tests/mtr/basic.test (+3/-0)
Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc (+36/-0)
Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result (+392/-0)
Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test (+44/-0)
Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc (+41/-0)
Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result (+1003/-0)
Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test (+28/-0)
Percona-Server/plugin/query_response_time/tests/mtr/suite.opt (+1/-0)
Percona-Server/plugin/query_response_time/tests/mtr/suite.pm (+12/-0)
Percona-Server/sql/sp_instr.cc (+6/-0)
Percona-Server/sql/sp_instr.h (+4/-0)
Percona-Server/sql/sql_class.h (+3/-3)
To merge this branch: bzr merge lp:~vlad-lesin/percona-server/5.6-query_response_time-audit
Reviewer Review Type Date Requested Status
Laurynas Biveinis (community) Approve on 2014-09-25
Stewart Smith (community) 2013-12-17 Needs Fixing on 2013-12-17
Registry Administrators 2014-07-15 Pending
Review via email: mp+199223@code.launchpad.net

Description of the change

To post a comment you must log in.
Stewart Smith (stewart) wrote :

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

    - 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

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) wrote :

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.

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) wrote :

> 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.

    - 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) wrote :

> - 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.

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

review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'Percona-Server/mysql-test/include/plugin.defs'
2--- Percona-Server/mysql-test/include/plugin.defs 2013-01-18 04:53:12 +0000
3+++ Percona-Server/mysql-test/include/plugin.defs 2013-12-17 07:03:32 +0000
4@@ -45,3 +45,4 @@
5 libmemcached plugin/innodb_memcached/daemon_memcached DAEMON_MEMCACHED daemon_memcached
6 innodb_engine plugin/innodb_memcached/innodb_memcache INNODB_ENGINE
7 validate_password plugin/password_validation VALIDATE_PASSWORD validate_password
8+query_response_time plugin/query_response_time PLUGIN_QUERY_RESPONSE_TIME QUERY_RESPONSE_TIME_AUDIT,QUERY_RESPONSE_TIME
9
10=== added directory 'Percona-Server/plugin/query_response_time'
11=== added file 'Percona-Server/plugin/query_response_time/CMakeLists.txt'
12--- Percona-Server/plugin/query_response_time/CMakeLists.txt 1970-01-01 00:00:00 +0000
13+++ Percona-Server/plugin/query_response_time/CMakeLists.txt 2013-12-17 07:03:32 +0000
14@@ -0,0 +1,2 @@
15+ADD_DEFINITIONS(-DHAVE_RESPONSE_TIME_DISTRIBUTION)
16+MYSQL_ADD_PLUGIN(QUERY_RESPONSE_TIME query_response_time.cc plugin.cc)
17
18=== added file 'Percona-Server/plugin/query_response_time/plugin.cc'
19--- Percona-Server/plugin/query_response_time/plugin.cc 1970-01-01 00:00:00 +0000
20+++ Percona-Server/plugin/query_response_time/plugin.cc 2013-12-17 07:03:32 +0000
21@@ -0,0 +1,170 @@
22+/* Copyright (C) 2013 Percona and Sergey Vojtovich
23+
24+ This program is free software; you can redistribute it and/or modify
25+ it under the terms of the GNU General Public License as published by
26+ the Free Software Foundation; version 2 of the License.
27+
28+ This program is distributed in the hope that it will be useful,
29+ but WITHOUT ANY WARRANTY; without even the implied warranty of
30+ MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
31+ GNU General Public License for more details.
32+
33+ You should have received a copy of the GNU General Public License
34+ along with this program; if not, write to the Free Software
35+ Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA */
36+
37+#define MYSQL_SERVER
38+#include <sql_class.h>
39+#include <table.h>
40+#include <sql_show.h>
41+#include <mysql/plugin_audit.h>
42+#include <sp_instr.h>
43+#include "query_response_time.h"
44+
45+
46+ulong opt_query_response_time_range_base= QRT_DEFAULT_BASE;
47+my_bool opt_query_response_time_stats= 0;
48+static my_bool opt_query_response_time_flush= 0;
49+
50+
51+static void query_response_time_flush_update(
52+ MYSQL_THD thd __attribute__((unused)),
53+ struct st_mysql_sys_var *var __attribute__((unused)),
54+ void *tgt __attribute__((unused)),
55+ const void *save __attribute__((unused)))
56+{
57+ query_response_time_flush();
58+}
59+
60+
61+static MYSQL_SYSVAR_ULONG(range_base, opt_query_response_time_range_base,
62+ PLUGIN_VAR_RQCMDARG,
63+ "Select base of log for query_response_time ranges. WARNING: variable "
64+ "change affect only after flush",
65+ NULL, NULL, QRT_DEFAULT_BASE, 2, QRT_MAXIMUM_BASE, 1);
66+static MYSQL_SYSVAR_BOOL(stats, opt_query_response_time_stats,
67+ PLUGIN_VAR_OPCMDARG,
68+ "Enable or disable query response time statisics collecting",
69+ NULL, NULL, FALSE);
70+static MYSQL_SYSVAR_BOOL(flush, opt_query_response_time_flush,
71+ PLUGIN_VAR_NOCMDOPT,
72+ "Update of this variable flushes statistics and re-reads "
73+ "query_response_time_range_base",
74+ NULL, query_response_time_flush_update, FALSE);
75+#ifndef DBUG_OFF
76+static MYSQL_THDVAR_ULONGLONG(exec_time_debug, PLUGIN_VAR_NOCMDOPT,
77+ "Pretend queries take this many microseconds. When 0 (the default) use "
78+ "the actual execution time. Used only for debugging.",
79+ NULL, NULL, 0, 0, LONG_TIMEOUT, 1);
80+#endif
81+
82+
83+static struct st_mysql_sys_var *query_response_time_info_vars[]=
84+{
85+ MYSQL_SYSVAR(range_base),
86+ MYSQL_SYSVAR(stats),
87+ MYSQL_SYSVAR(flush),
88+#ifndef DBUG_OFF
89+ MYSQL_SYSVAR(exec_time_debug),
90+#endif
91+ NULL
92+};
93+
94+
95+ST_FIELD_INFO query_response_time_fields_info[] =
96+{
97+ { "TIME", QRT_TIME_STRING_LENGTH, MYSQL_TYPE_STRING, 0, 0, "", SKIP_OPEN_TABLE },
98+ { "COUNT", MY_INT32_NUM_DECIMAL_DIGITS, MYSQL_TYPE_LONG, 0, MY_I_S_UNSIGNED, "", SKIP_OPEN_TABLE },
99+ { "TOTAL", QRT_TIME_STRING_LENGTH, MYSQL_TYPE_STRING, 0, 0, "", SKIP_OPEN_TABLE },
100+ { 0, 0, MYSQL_TYPE_NULL, 0, 0, 0, 0 }
101+};
102+
103+
104+static int query_response_time_info_init(void *p)
105+{
106+ ST_SCHEMA_TABLE *i_s_query_response_time= (ST_SCHEMA_TABLE *) p;
107+ i_s_query_response_time->fields_info= query_response_time_fields_info;
108+ i_s_query_response_time->fill_table= query_response_time_fill;
109+ query_response_time_init();
110+ return 0;
111+}
112+
113+
114+static int query_response_time_info_deinit(void *arg __attribute__((unused)))
115+{
116+ opt_query_response_time_stats= 0;
117+ query_response_time_free();
118+ return 0;
119+}
120+
121+
122+static struct st_mysql_information_schema query_response_time_info_descriptor=
123+{ MYSQL_INFORMATION_SCHEMA_INTERFACE_VERSION };
124+
125+static void query_response_time_audit_notify(MYSQL_THD thd,
126+ unsigned int event_class,
127+ const void *event)
128+{
129+ const struct mysql_event_general *event_general=
130+ (const struct mysql_event_general *) event;
131+ DBUG_ASSERT(event_class == MYSQL_AUDIT_GENERAL_CLASS);
132+ if (event_general->event_subclass == MYSQL_AUDIT_GENERAL_STATUS &&
133+ opt_query_response_time_stats)
134+ {
135+#ifndef DBUG_OFF
136+ if (THDVAR(thd, exec_time_debug)) {
137+ ulonglong t = THDVAR(thd, exec_time_debug);
138+ if ((thd->lex->sql_command == SQLCOM_SET_OPTION) ||
139+ (thd->lex->spname && thd->stmt_arena &&
140+ ((sp_lex_instr *)thd->stmt_arena)->get_command() ==
141+ SQLCOM_SET_OPTION )) {
142+ t = 0;
143+ }
144+ query_response_time_collect(t);
145+ }
146+ else
147+#endif
148+ query_response_time_collect(thd->utime_after_query - thd->utime_after_lock);
149+ }
150+}
151+
152+
153+static struct st_mysql_audit query_response_time_audit_descriptor=
154+{
155+ MYSQL_AUDIT_INTERFACE_VERSION, NULL, query_response_time_audit_notify,
156+ { (unsigned long) MYSQL_AUDIT_GENERAL_CLASSMASK }
157+};
158+
159+
160+mysql_declare_plugin(query_response_time)
161+{
162+ MYSQL_INFORMATION_SCHEMA_PLUGIN,
163+ &query_response_time_info_descriptor,
164+ "QUERY_RESPONSE_TIME",
165+ "Percona and Sergey Vojtovich",
166+ "Query Response Time Distribution INFORMATION_SCHEMA Plugin",
167+ PLUGIN_LICENSE_GPL,
168+ query_response_time_info_init,
169+ query_response_time_info_deinit,
170+ 0x0100,
171+ NULL,
172+ query_response_time_info_vars,
173+ (void *)"1.0",
174+ 0,
175+},
176+{
177+ MYSQL_AUDIT_PLUGIN,
178+ &query_response_time_audit_descriptor,
179+ "QUERY_RESPONSE_TIME_AUDIT",
180+ "Percona and Sergey Vojtovich",
181+ "Query Response Time Distribution Audit Plugin",
182+ PLUGIN_LICENSE_GPL,
183+ NULL,
184+ NULL,
185+ 0x0100,
186+ NULL,
187+ NULL,
188+ (void *)"1.0",
189+ 0,
190+}
191+mysql_declare_plugin_end;
192
193=== added file 'Percona-Server/plugin/query_response_time/query_response_time.cc'
194--- Percona-Server/plugin/query_response_time/query_response_time.cc 1970-01-01 00:00:00 +0000
195+++ Percona-Server/plugin/query_response_time/query_response_time.cc 2013-12-17 07:03:32 +0000
196@@ -0,0 +1,302 @@
197+#include "mysql_version.h"
198+#include "my_global.h"
199+#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
200+#include "mysql_com.h"
201+#include "rpl_tblmap.h"
202+#include "table.h"
203+#include "field.h"
204+#include "sql_show.h"
205+#include "query_response_time.h"
206+
207+#define TIME_STRING_POSITIVE_POWER_LENGTH QRT_TIME_STRING_POSITIVE_POWER_LENGTH
208+#define TIME_STRING_NEGATIVE_POWER_LENGTH 6
209+#define TOTAL_STRING_POSITIVE_POWER_LENGTH QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH
210+#define TOTAL_STRING_NEGATIVE_POWER_LENGTH 6
211+#define MINIMUM_BASE 2
212+#define MAXIMUM_BASE QRT_MAXIMUM_BASE
213+#define POSITIVE_POWER_FILLER QRT_POSITIVE_POWER_FILLER
214+#define NEGATIVE_POWER_FILLER QRT_NEGATIVE_POWER_FILLER
215+#define TIME_OVERFLOW QRT_TIME_OVERFLOW
216+#define DEFAULT_BASE QRT_DEFAULT_BASE
217+
218+#define do_xstr(s) do_str(s)
219+#define do_str(s) #s
220+#define do_format(filler,width) "%" filler width "lld"
221+/*
222+ Format strings for snprintf. Generate from:
223+ POSITIVE_POWER_FILLER and TIME_STRING_POSITIVE_POWER_LENGTH
224+ NEFATIVE_POWER_FILLER and TIME_STRING_NEGATIVE_POWER_LENGTH
225+*/
226+#define TIME_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TIME_STRING_POSITIVE_POWER_LENGTH))
227+#define TIME_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TIME_STRING_NEGATIVE_POWER_LENGTH))
228+#define TIME_STRING_FORMAT TIME_STRING_POSITIVE_POWER_FORMAT "." TIME_STRING_NEGATIVE_POWER_FORMAT
229+
230+#define TOTAL_STRING_POSITIVE_POWER_FORMAT do_format(POSITIVE_POWER_FILLER,do_xstr(TOTAL_STRING_POSITIVE_POWER_LENGTH))
231+#define TOTAL_STRING_NEGATIVE_POWER_FORMAT do_format(NEGATIVE_POWER_FILLER,do_xstr(TOTAL_STRING_NEGATIVE_POWER_LENGTH))
232+#define TOTAL_STRING_FORMAT TOTAL_STRING_POSITIVE_POWER_FORMAT "." TOTAL_STRING_NEGATIVE_POWER_FORMAT
233+
234+#define TIME_STRING_LENGTH QRT_TIME_STRING_LENGTH
235+#define TIME_STRING_BUFFER_LENGTH (TIME_STRING_LENGTH + 1 /* '\0' */)
236+
237+#define TOTAL_STRING_LENGTH QRT_TOTAL_STRING_LENGTH
238+#define TOTAL_STRING_BUFFER_LENGTH (TOTAL_STRING_LENGTH + 1 /* '\0' */)
239+
240+/*
241+ Calculate length of "log linear"
242+ 1)
243+ (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH) < (MINIMUM_BASE ^ (result + 1))
244+
245+ 2)
246+ (MINIMUM_BASE ^ result) <= (10 ^ STRING_POWER_LENGTH)
247+ and
248+ (MINIMUM_BASE ^ (result + 1)) > (10 ^ STRING_POWER_LENGTH)
249+
250+ 3)
251+ result <= LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
252+ result + 1 > LOG(MINIMUM_BASE, 10 ^ STRING_POWER_LENGTH)= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
253+
254+ 4) STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10) - 1 < result <= STRING_POWER_LENGTH * LOG(MINIMUM_BASE,10)
255+
256+ MINIMUM_BASE= 2 always, LOG(MINIMUM_BASE,10)= 3.3219280948873626, result= (int)3.3219280948873626 * STRING_POWER_LENGTH
257+
258+ Last counter always use for time overflow
259+*/
260+#define POSITIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_POSITIVE_POWER_LENGTH))
261+#define NEGATIVE_POWER_COUNT ((int)(3.32192809 * TIME_STRING_NEGATIVE_POWER_LENGTH))
262+#define OVERALL_POWER_COUNT (NEGATIVE_POWER_COUNT + 1 + POSITIVE_POWER_COUNT)
263+
264+#define MILLION ((unsigned long)1000 * 1000)
265+
266+namespace query_response_time
267+{
268+
269+class utility
270+{
271+public:
272+ utility() : m_base(0)
273+ {
274+ m_max_dec_value= MILLION;
275+ for(int i= 0; TIME_STRING_POSITIVE_POWER_LENGTH > i; ++i)
276+ m_max_dec_value *= 10;
277+ setup(DEFAULT_BASE);
278+ }
279+public:
280+ uint base() const { return m_base; }
281+ uint negative_count() const { return m_negative_count; }
282+ uint positive_count() const { return m_positive_count; }
283+ uint bound_count() const { return m_bound_count; }
284+ ulonglong max_dec_value() const { return m_max_dec_value; }
285+ ulonglong bound(uint index) const { return m_bound[ index ]; }
286+public:
287+ void setup(uint base)
288+ {
289+ if(base != m_base)
290+ {
291+ m_base= base;
292+
293+ const ulonglong million= 1000 * 1000;
294+ ulonglong value= million;
295+ m_negative_count= 0;
296+ while(value > 0)
297+ {
298+ m_negative_count += 1;
299+ value /= m_base;
300+ }
301+ m_negative_count -= 1;
302+
303+ value= million;
304+ m_positive_count= 0;
305+ while(value < m_max_dec_value)
306+ {
307+ m_positive_count += 1;
308+ value *= m_base;
309+ }
310+ m_bound_count= m_negative_count + m_positive_count;
311+
312+ value= million;
313+ for(uint i= 0; i < m_negative_count; ++i)
314+ {
315+ value /= m_base;
316+ m_bound[m_negative_count - i - 1]= value;
317+ }
318+ value= million;
319+ for(uint i= 0; i < m_positive_count; ++i)
320+ {
321+ m_bound[m_negative_count + i]= value;
322+ value *= m_base;
323+ }
324+ }
325+ }
326+private:
327+ uint m_base;
328+ uint m_negative_count;
329+ uint m_positive_count;
330+ uint m_bound_count;
331+ ulonglong m_max_dec_value; /* for TIME_STRING_POSITIVE_POWER_LENGTH=7 is 10000000 */
332+ ulonglong m_bound[OVERALL_POWER_COUNT];
333+};
334+
335+static
336+void print_time(char* buffer, std::size_t buffer_size, const char* format,
337+ uint64 value)
338+{
339+ ulonglong second= (value / MILLION);
340+ ulonglong microsecond= (value % MILLION);
341+ my_snprintf(buffer, buffer_size, format, second, microsecond);
342+}
343+
344+class time_collector
345+{
346+public:
347+ time_collector(utility& u) : m_utility(&u)
348+ {
349+ my_atomic_rwlock_init(&time_collector_lock);
350+ }
351+ ~time_collector()
352+ {
353+ my_atomic_rwlock_destroy(&time_collector_lock);
354+ }
355+ uint32 count(uint index)
356+ {
357+ my_atomic_rwlock_rdlock(&time_collector_lock);
358+ uint32 result= my_atomic_load32((int32*)&m_count[index]);
359+ my_atomic_rwlock_rdunlock(&time_collector_lock);
360+ return result;
361+ }
362+ uint64 total(uint index)
363+ {
364+ my_atomic_rwlock_rdlock(&time_collector_lock);
365+ uint64 result= my_atomic_load64((int64*)&m_total[index]);
366+ my_atomic_rwlock_rdunlock(&time_collector_lock);
367+ return result;
368+ }
369+public:
370+ void flush()
371+ {
372+ my_atomic_rwlock_wrlock(&time_collector_lock);
373+ memset((void*)&m_count,0,sizeof(m_count));
374+ memset((void*)&m_total,0,sizeof(m_total));
375+ my_atomic_rwlock_wrunlock(&time_collector_lock);
376+ }
377+ void collect(uint64 time)
378+ {
379+ int i= 0;
380+ for(int count= m_utility->bound_count(); count > i; ++i)
381+ {
382+ if(m_utility->bound(i) > time)
383+ {
384+ my_atomic_rwlock_wrlock(&time_collector_lock);
385+ my_atomic_add32((int32*)(&m_count[i]), 1);
386+ my_atomic_add64((int64*)(&m_total[i]), time);
387+ my_atomic_rwlock_wrunlock(&time_collector_lock);
388+ break;
389+ }
390+ }
391+ }
392+private:
393+ utility* m_utility;
394+ /* The lock for atomic operations on m_count and m_total. Only actually
395+ used on architectures that do not have atomic implementation of atomic
396+ operations. */
397+ my_atomic_rwlock_t time_collector_lock;
398+ uint32 m_count[OVERALL_POWER_COUNT + 1];
399+ uint64 m_total[OVERALL_POWER_COUNT + 1];
400+};
401+
402+class collector
403+{
404+public:
405+ collector() : m_time(m_utility)
406+ {
407+ m_utility.setup(DEFAULT_BASE);
408+ m_time.flush();
409+ }
410+public:
411+ void flush()
412+ {
413+ m_utility.setup(opt_query_response_time_range_base);
414+ m_time.flush();
415+ }
416+ int fill(THD* thd, TABLE_LIST *tables, COND *cond)
417+ {
418+ DBUG_ENTER("fill_schema_query_response_time");
419+ TABLE *table= static_cast<TABLE*>(tables->table);
420+ Field **fields= table->field;
421+ for(uint i= 0, count= bound_count() + 1 /* with overflow */; count > i; ++i)
422+ {
423+ char time[TIME_STRING_BUFFER_LENGTH];
424+ char total[TOTAL_STRING_BUFFER_LENGTH];
425+ if(i == bound_count())
426+ {
427+ assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH);
428+ assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH);
429+ memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
430+ memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
431+ }
432+ else
433+ {
434+ print_time(time, sizeof(time), TIME_STRING_FORMAT, this->bound(i));
435+ print_time(total, sizeof(total), TOTAL_STRING_FORMAT, this->total(i));
436+ }
437+ fields[0]->store(time,strlen(time),system_charset_info);
438+ fields[1]->store(this->count(i));
439+ fields[2]->store(total,strlen(total),system_charset_info);
440+ if (schema_table_store_record(thd, table))
441+ {
442+ DBUG_RETURN(1);
443+ }
444+ }
445+ DBUG_RETURN(0);
446+ }
447+ void collect(ulonglong time)
448+ {
449+ m_time.collect(time);
450+ }
451+ uint bound_count() const
452+ {
453+ return m_utility.bound_count();
454+ }
455+ ulonglong bound(uint index)
456+ {
457+ return m_utility.bound(index);
458+ }
459+ ulonglong count(uint index)
460+ {
461+ return m_time.count(index);
462+ }
463+ ulonglong total(uint index)
464+ {
465+ return m_time.total(index);
466+ }
467+private:
468+ utility m_utility;
469+ time_collector m_time;
470+};
471+
472+static collector g_collector;
473+
474+} // namespace query_response_time
475+
476+void query_response_time_init()
477+{
478+}
479+
480+void query_response_time_free()
481+{
482+ query_response_time::g_collector.flush();
483+}
484+
485+void query_response_time_flush()
486+{
487+ query_response_time::g_collector.flush();
488+}
489+void query_response_time_collect(ulonglong query_time)
490+{
491+ query_response_time::g_collector.collect(query_time);
492+}
493+
494+int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
495+{
496+ return query_response_time::g_collector.fill(thd,tables,cond);
497+}
498+#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
499
500=== added file 'Percona-Server/plugin/query_response_time/query_response_time.h'
501--- Percona-Server/plugin/query_response_time/query_response_time.h 1970-01-01 00:00:00 +0000
502+++ Percona-Server/plugin/query_response_time/query_response_time.h 2013-12-17 07:03:32 +0000
503@@ -0,0 +1,69 @@
504+#ifndef QUERY_RESPONSE_TIME_H
505+#define QUERY_RESPONSE_TIME_H
506+
507+/*
508+ Settings for query response time
509+*/
510+
511+/*
512+ Maximum string length for (10 ^ (-1 * QRT_STRING_NEGATIVE_POWER_LENGTH)) in text representation.
513+ Example: for 6 is 0.000001
514+ Always 2
515+
516+ Maximum string length for (10 ^ (QRT_STRING_POSITIVE_POWER_LENGTH + 1) - 1) in text representation.
517+ Example: for 7 is 9999999.0
518+*/
519+#define QRT_TIME_STRING_POSITIVE_POWER_LENGTH 7
520+#define QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH 7
521+
522+/*
523+ Minimum base for log - ALWAYS 2
524+ Maximum base for log:
525+*/
526+#define QRT_MAXIMUM_BASE 1000
527+
528+/*
529+ Filler for whole number (positive power)
530+ Example: for
531+ QRT_POSITIVE_POWER_FILLER ' '
532+ QRT_POSITIVE_POWER_LENGTH 7
533+ and number 7234 result is:
534+ ' 7234'
535+*/
536+#define QRT_POSITIVE_POWER_FILLER ""
537+/*
538+ Filler for fractional number. Similiary to whole number
539+*/
540+#define QRT_NEGATIVE_POWER_FILLER "0"
541+
542+/*
543+ Message if time too big for statistic collecting (very long query)
544+*/
545+#define QRT_TIME_OVERFLOW "TOO LONG"
546+
547+#define QRT_DEFAULT_BASE 10
548+
549+#define QRT_TIME_STRING_LENGTH \
550+ MY_MAX( (QRT_TIME_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TIME_STRING_NEGATIVE_POWER_LENGTH*/), \
551+ (sizeof(QRT_TIME_OVERFLOW) - 1) )
552+
553+#define QRT_TOTAL_STRING_LENGTH \
554+ MY_MAX( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \
555+ (sizeof(QRT_TIME_OVERFLOW) - 1) )
556+
557+extern ST_SCHEMA_TABLE query_response_time_table;
558+
559+#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
560+typedef class Item COND;
561+
562+extern void query_response_time_init ();
563+extern void query_response_time_free ();
564+extern void query_response_time_flush ();
565+extern void query_response_time_collect(ulonglong query_time);
566+extern int query_response_time_fill (THD* thd, TABLE_LIST *tables, COND *cond);
567+
568+extern ulong opt_query_response_time_range_base;
569+extern my_bool opt_query_response_time_stats;
570+#endif // HAVE_RESPONSE_TIME_DISTRIBUTION
571+
572+#endif // QUERY_RESPONSE_TIME_H
573
574=== added directory 'Percona-Server/plugin/query_response_time/tests'
575=== added directory 'Percona-Server/plugin/query_response_time/tests/mtr'
576=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/basic.result'
577--- Percona-Server/plugin/query_response_time/tests/mtr/basic.result 1970-01-01 00:00:00 +0000
578+++ Percona-Server/plugin/query_response_time/tests/mtr/basic.result 2013-12-17 07:03:32 +0000
579@@ -0,0 +1,25 @@
580+SHOW VARIABLES WHERE VARIABLE_NAME LIKE 'query_response_time%' AND VARIABLE_NAME!='query_response_time_exec_time_debug';
581+Variable_name Value
582+query_response_time_flush OFF
583+query_response_time_range_base 10
584+query_response_time_stats OFF
585+SHOW CREATE TABLE INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
586+Table Create Table
587+QUERY_RESPONSE_TIME CREATE TEMPORARY TABLE `QUERY_RESPONSE_TIME` (
588+ `TIME` varchar(14) NOT NULL DEFAULT '',
589+ `COUNT` int(11) unsigned NOT NULL DEFAULT '0',
590+ `TOTAL` varchar(14) NOT NULL DEFAULT ''
591+) ENGINE=MEMORY DEFAULT CHARSET=utf8
592+SELECT PLUGIN_NAME, PLUGIN_VERSION, PLUGIN_TYPE, PLUGIN_AUTHOR, PLUGIN_DESCRIPTION, PLUGIN_LICENSE FROM INFORMATION_SCHEMA.PLUGINS WHERE PLUGIN_NAME LIKE 'query_response_time%';;
593+PLUGIN_NAME QUERY_RESPONSE_TIME_AUDIT
594+PLUGIN_VERSION 1.0
595+PLUGIN_TYPE AUDIT
596+PLUGIN_AUTHOR Percona and Sergey Vojtovich
597+PLUGIN_DESCRIPTION Query Response Time Distribution Audit Plugin
598+PLUGIN_LICENSE GPL
599+PLUGIN_NAME QUERY_RESPONSE_TIME
600+PLUGIN_VERSION 1.0
601+PLUGIN_TYPE INFORMATION SCHEMA
602+PLUGIN_AUTHOR Percona and Sergey Vojtovich
603+PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
604+PLUGIN_LICENSE GPL
605
606=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/basic.test'
607--- Percona-Server/plugin/query_response_time/tests/mtr/basic.test 1970-01-01 00:00:00 +0000
608+++ Percona-Server/plugin/query_response_time/tests/mtr/basic.test 2013-12-17 07:03:32 +0000
609@@ -0,0 +1,3 @@
610+SHOW VARIABLES WHERE VARIABLE_NAME LIKE 'query_response_time%' AND VARIABLE_NAME!='query_response_time_exec_time_debug';
611+SHOW CREATE TABLE INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
612+--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%';
613
614=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc'
615--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc 1970-01-01 00:00:00 +0000
616+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.inc 2013-12-17 07:03:32 +0000
617@@ -0,0 +1,36 @@
618+SET SESSION query_response_time_exec_time_debug=100000;
619+
620+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
621+EVAL SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=$base;
622+SET GLOBAL query_response_time_flush=1;
623+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
624+
625+CALL test_f(310000);
626+CALL test_f(320000);
627+CALL test_f(330000);
628+CALL test_f(340000);
629+CALL test_f(350000);
630+CALL test_f(360000);
631+CALL test_f(370000);
632+CALL test_f(380000);
633+CALL test_f(390000);
634+CALL test_f(400000);
635+CALL test_f(1100000);
636+CALL test_f(1200000);
637+CALL test_f(1300000);
638+CALL test_f(1500000);
639+CALL test_f(1400000);
640+CALL test_f(500000);
641+CALL test_f(2100000);
642+CALL test_f(2300000);
643+CALL test_f(2500000);
644+CALL test_f(3100000);
645+CALL test_f(4100000);
646+CALL test_f(5100000);
647+
648+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
649+
650+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
651+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
652+
653+SET SESSION query_response_time_exec_time_debug=default;
654
655=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result'
656--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result 1970-01-01 00:00:00 +0000
657+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.result 2013-12-17 07:03:32 +0000
658@@ -0,0 +1,392 @@
659+CREATE TABLE t(a INT);
660+CREATE PROCEDURE test_f(t INT)
661+BEGIN
662+SET SESSION query_response_time_exec_time_debug=t;
663+INSERT INTO t VALUES(1);
664+SET SESSION query_response_time_exec_time_debug=100000;
665+DELETE FROM t;
666+END^
667+SET SESSION query_response_time_exec_time_debug=100000;
668+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
669+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1;
670+Warnings:
671+Warning 1292 Truncated incorrect query_response_time_range_base value: '1'
672+SET GLOBAL query_response_time_flush=1;
673+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
674+CALL test_f(310000);
675+CALL test_f(320000);
676+CALL test_f(330000);
677+CALL test_f(340000);
678+CALL test_f(350000);
679+CALL test_f(360000);
680+CALL test_f(370000);
681+CALL test_f(380000);
682+CALL test_f(390000);
683+CALL test_f(400000);
684+CALL test_f(1100000);
685+CALL test_f(1200000);
686+CALL test_f(1300000);
687+CALL test_f(1500000);
688+CALL test_f(1400000);
689+CALL test_f(500000);
690+CALL test_f(2100000);
691+CALL test_f(2300000);
692+CALL test_f(2500000);
693+CALL test_f(3100000);
694+CALL test_f(4100000);
695+CALL test_f(5100000);
696+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
697+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
698+Variable_name Value
699+query_response_time_range_base 2
700+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
701+TIME COUNT TOTAL
702+ 0.000001 45 0.000000
703+ 0.000003 0 0.000000
704+ 0.000007 0 0.000000
705+ 0.000015 0 0.000000
706+ 0.000030 0 0.000000
707+ 0.000061 0 0.000000
708+ 0.000122 0 0.000000
709+ 0.000244 0 0.000000
710+ 0.000488 0 0.000000
711+ 0.000976 0 0.000000
712+ 0.001953 0 0.000000
713+ 0.003906 0 0.000000
714+ 0.007812 0 0.000000
715+ 0.015625 0 0.000000
716+ 0.031250 0 0.000000
717+ 0.062500 0 0.000000
718+ 0.125000 44 4.400000
719+ 0.250000 0 0.000000
720+ 0.500000 10 3.550000
721+ 1.000000 1 0.500000
722+ 2.000000 5 6.500000
723+ 4.000000 4 10.000000
724+ 8.000000 2 9.200000
725+ 16.000000 0 0.000000
726+ 32.000000 0 0.000000
727+ 64.000000 0 0.000000
728+ 128.000000 0 0.000000
729+ 256.000000 0 0.000000
730+ 512.000000 0 0.000000
731+ 1024.000000 0 0.000000
732+ 2048.000000 0 0.000000
733+ 4096.000000 0 0.000000
734+ 8192.000000 0 0.000000
735+ 16384.000000 0 0.000000
736+ 32768.000000 0 0.000000
737+ 65536.000000 0 0.000000
738+ 131072.000000 0 0.000000
739+ 262144.000000 0 0.000000
740+ 524288.000000 0 0.000000
741+1048576.000000 0 0.000000
742+2097152.000000 0 0.000000
743+4194304.000000 0 0.000000
744+8388608.000000 0 0.000000
745+TOO LONG 0 TOO LONG
746+SET SESSION query_response_time_exec_time_debug=default;
747+SET SESSION query_response_time_exec_time_debug=100000;
748+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
749+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=2;
750+SET GLOBAL query_response_time_flush=1;
751+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
752+CALL test_f(310000);
753+CALL test_f(320000);
754+CALL test_f(330000);
755+CALL test_f(340000);
756+CALL test_f(350000);
757+CALL test_f(360000);
758+CALL test_f(370000);
759+CALL test_f(380000);
760+CALL test_f(390000);
761+CALL test_f(400000);
762+CALL test_f(1100000);
763+CALL test_f(1200000);
764+CALL test_f(1300000);
765+CALL test_f(1500000);
766+CALL test_f(1400000);
767+CALL test_f(500000);
768+CALL test_f(2100000);
769+CALL test_f(2300000);
770+CALL test_f(2500000);
771+CALL test_f(3100000);
772+CALL test_f(4100000);
773+CALL test_f(5100000);
774+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
775+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
776+Variable_name Value
777+query_response_time_range_base 2
778+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
779+TIME COUNT TOTAL
780+ 0.000001 45 0.000000
781+ 0.000003 0 0.000000
782+ 0.000007 0 0.000000
783+ 0.000015 0 0.000000
784+ 0.000030 0 0.000000
785+ 0.000061 0 0.000000
786+ 0.000122 0 0.000000
787+ 0.000244 0 0.000000
788+ 0.000488 0 0.000000
789+ 0.000976 0 0.000000
790+ 0.001953 0 0.000000
791+ 0.003906 0 0.000000
792+ 0.007812 0 0.000000
793+ 0.015625 0 0.000000
794+ 0.031250 0 0.000000
795+ 0.062500 0 0.000000
796+ 0.125000 44 4.400000
797+ 0.250000 0 0.000000
798+ 0.500000 10 3.550000
799+ 1.000000 1 0.500000
800+ 2.000000 5 6.500000
801+ 4.000000 4 10.000000
802+ 8.000000 2 9.200000
803+ 16.000000 0 0.000000
804+ 32.000000 0 0.000000
805+ 64.000000 0 0.000000
806+ 128.000000 0 0.000000
807+ 256.000000 0 0.000000
808+ 512.000000 0 0.000000
809+ 1024.000000 0 0.000000
810+ 2048.000000 0 0.000000
811+ 4096.000000 0 0.000000
812+ 8192.000000 0 0.000000
813+ 16384.000000 0 0.000000
814+ 32768.000000 0 0.000000
815+ 65536.000000 0 0.000000
816+ 131072.000000 0 0.000000
817+ 262144.000000 0 0.000000
818+ 524288.000000 0 0.000000
819+1048576.000000 0 0.000000
820+2097152.000000 0 0.000000
821+4194304.000000 0 0.000000
822+8388608.000000 0 0.000000
823+TOO LONG 0 TOO LONG
824+SET SESSION query_response_time_exec_time_debug=default;
825+SET SESSION query_response_time_exec_time_debug=100000;
826+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
827+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=10;
828+SET GLOBAL query_response_time_flush=1;
829+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
830+CALL test_f(310000);
831+CALL test_f(320000);
832+CALL test_f(330000);
833+CALL test_f(340000);
834+CALL test_f(350000);
835+CALL test_f(360000);
836+CALL test_f(370000);
837+CALL test_f(380000);
838+CALL test_f(390000);
839+CALL test_f(400000);
840+CALL test_f(1100000);
841+CALL test_f(1200000);
842+CALL test_f(1300000);
843+CALL test_f(1500000);
844+CALL test_f(1400000);
845+CALL test_f(500000);
846+CALL test_f(2100000);
847+CALL test_f(2300000);
848+CALL test_f(2500000);
849+CALL test_f(3100000);
850+CALL test_f(4100000);
851+CALL test_f(5100000);
852+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
853+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
854+Variable_name Value
855+query_response_time_range_base 10
856+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
857+TIME COUNT TOTAL
858+ 0.000001 45 0.000000
859+ 0.000010 0 0.000000
860+ 0.000100 0 0.000000
861+ 0.001000 0 0.000000
862+ 0.010000 0 0.000000
863+ 0.100000 0 0.000000
864+ 1.000000 55 8.450000
865+ 10.000000 11 25.700000
866+ 100.000000 0 0.000000
867+ 1000.000000 0 0.000000
868+ 10000.000000 0 0.000000
869+ 100000.000000 0 0.000000
870+1000000.000000 0 0.000000
871+TOO LONG 0 TOO LONG
872+SET SESSION query_response_time_exec_time_debug=default;
873+SET SESSION query_response_time_exec_time_debug=100000;
874+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
875+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=7;
876+SET GLOBAL query_response_time_flush=1;
877+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
878+CALL test_f(310000);
879+CALL test_f(320000);
880+CALL test_f(330000);
881+CALL test_f(340000);
882+CALL test_f(350000);
883+CALL test_f(360000);
884+CALL test_f(370000);
885+CALL test_f(380000);
886+CALL test_f(390000);
887+CALL test_f(400000);
888+CALL test_f(1100000);
889+CALL test_f(1200000);
890+CALL test_f(1300000);
891+CALL test_f(1500000);
892+CALL test_f(1400000);
893+CALL test_f(500000);
894+CALL test_f(2100000);
895+CALL test_f(2300000);
896+CALL test_f(2500000);
897+CALL test_f(3100000);
898+CALL test_f(4100000);
899+CALL test_f(5100000);
900+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
901+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
902+Variable_name Value
903+query_response_time_range_base 7
904+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
905+TIME COUNT TOTAL
906+ 0.000001 45 0.000000
907+ 0.000008 0 0.000000
908+ 0.000059 0 0.000000
909+ 0.000416 0 0.000000
910+ 0.002915 0 0.000000
911+ 0.020408 0 0.000000
912+ 0.142857 44 4.400000
913+ 1.000000 11 4.050000
914+ 7.000000 11 25.700000
915+ 49.000000 0 0.000000
916+ 343.000000 0 0.000000
917+ 2401.000000 0 0.000000
918+ 16807.000000 0 0.000000
919+ 117649.000000 0 0.000000
920+ 823543.000000 0 0.000000
921+5764801.000000 0 0.000000
922+TOO LONG 0 TOO LONG
923+SET SESSION query_response_time_exec_time_debug=default;
924+SET SESSION query_response_time_exec_time_debug=100000;
925+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
926+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=156;
927+SET GLOBAL query_response_time_flush=1;
928+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
929+CALL test_f(310000);
930+CALL test_f(320000);
931+CALL test_f(330000);
932+CALL test_f(340000);
933+CALL test_f(350000);
934+CALL test_f(360000);
935+CALL test_f(370000);
936+CALL test_f(380000);
937+CALL test_f(390000);
938+CALL test_f(400000);
939+CALL test_f(1100000);
940+CALL test_f(1200000);
941+CALL test_f(1300000);
942+CALL test_f(1500000);
943+CALL test_f(1400000);
944+CALL test_f(500000);
945+CALL test_f(2100000);
946+CALL test_f(2300000);
947+CALL test_f(2500000);
948+CALL test_f(3100000);
949+CALL test_f(4100000);
950+CALL test_f(5100000);
951+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
952+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
953+Variable_name Value
954+query_response_time_range_base 156
955+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
956+TIME COUNT TOTAL
957+ 0.000041 45 0.000000
958+ 0.006410 0 0.000000
959+ 1.000000 55 8.450000
960+ 156.000000 11 25.700000
961+ 24336.000000 0 0.000000
962+3796416.000000 0 0.000000
963+TOO LONG 0 TOO LONG
964+SET SESSION query_response_time_exec_time_debug=default;
965+SET SESSION query_response_time_exec_time_debug=100000;
966+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
967+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1000;
968+SET GLOBAL query_response_time_flush=1;
969+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
970+CALL test_f(310000);
971+CALL test_f(320000);
972+CALL test_f(330000);
973+CALL test_f(340000);
974+CALL test_f(350000);
975+CALL test_f(360000);
976+CALL test_f(370000);
977+CALL test_f(380000);
978+CALL test_f(390000);
979+CALL test_f(400000);
980+CALL test_f(1100000);
981+CALL test_f(1200000);
982+CALL test_f(1300000);
983+CALL test_f(1500000);
984+CALL test_f(1400000);
985+CALL test_f(500000);
986+CALL test_f(2100000);
987+CALL test_f(2300000);
988+CALL test_f(2500000);
989+CALL test_f(3100000);
990+CALL test_f(4100000);
991+CALL test_f(5100000);
992+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
993+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
994+Variable_name Value
995+query_response_time_range_base 1000
996+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
997+TIME COUNT TOTAL
998+ 0.000001 45 0.000000
999+ 0.001000 0 0.000000
1000+ 1.000000 55 8.450000
1001+ 1000.000000 11 25.700000
1002+1000000.000000 0 0.000000
1003+TOO LONG 0 TOO LONG
1004+SET SESSION query_response_time_exec_time_debug=default;
1005+SET SESSION query_response_time_exec_time_debug=100000;
1006+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1007+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1001;
1008+Warnings:
1009+Warning 1292 Truncated incorrect query_response_time_range_base value: '1001'
1010+SET GLOBAL query_response_time_flush=1;
1011+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1012+CALL test_f(310000);
1013+CALL test_f(320000);
1014+CALL test_f(330000);
1015+CALL test_f(340000);
1016+CALL test_f(350000);
1017+CALL test_f(360000);
1018+CALL test_f(370000);
1019+CALL test_f(380000);
1020+CALL test_f(390000);
1021+CALL test_f(400000);
1022+CALL test_f(1100000);
1023+CALL test_f(1200000);
1024+CALL test_f(1300000);
1025+CALL test_f(1500000);
1026+CALL test_f(1400000);
1027+CALL test_f(500000);
1028+CALL test_f(2100000);
1029+CALL test_f(2300000);
1030+CALL test_f(2500000);
1031+CALL test_f(3100000);
1032+CALL test_f(4100000);
1033+CALL test_f(5100000);
1034+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1035+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1036+Variable_name Value
1037+query_response_time_range_base 1000
1038+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1039+TIME COUNT TOTAL
1040+ 0.000001 45 0.000000
1041+ 0.001000 0 0.000000
1042+ 1.000000 55 8.450000
1043+ 1000.000000 11 25.700000
1044+1000000.000000 0 0.000000
1045+TOO LONG 0 TOO LONG
1046+SET SESSION query_response_time_exec_time_debug=default;
1047+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
1048+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
1049+DROP PROCEDURE test_f;
1050+DROP TABLE t;
1051
1052=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test'
1053--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test 1970-01-01 00:00:00 +0000
1054+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time-stored.test 2013-12-17 07:03:32 +0000
1055@@ -0,0 +1,44 @@
1056+--source include/have_debug.inc
1057+
1058+# The file with expected results fits only to a run without
1059+# ps-protocol/sp-protocol/cursor-protocol/view-protocol.
1060+if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
1061+ + $VIEW_PROTOCOL > 0`)
1062+{
1063+ --skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
1064+}
1065+
1066+
1067+CREATE TABLE t(a INT);
1068+
1069+delimiter ^;
1070+CREATE PROCEDURE test_f(t INT)
1071+BEGIN
1072+ SET SESSION query_response_time_exec_time_debug=t;
1073+ INSERT INTO t VALUES(1);
1074+ SET SESSION query_response_time_exec_time_debug=100000;
1075+ DELETE FROM t;
1076+END^
1077+delimiter ;^
1078+
1079+--let base=1
1080+--source query_response_time-stored.inc
1081+--let base=2
1082+--source query_response_time-stored.inc
1083+--let base=10
1084+--source query_response_time-stored.inc
1085+--let base=7
1086+--source query_response_time-stored.inc
1087+--let base=156
1088+--source query_response_time-stored.inc
1089+--let base=1000
1090+--source query_response_time-stored.inc
1091+--let base=1001
1092+--source query_response_time-stored.inc
1093+
1094+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
1095+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
1096+
1097+DROP PROCEDURE test_f;
1098+
1099+DROP TABLE t;
1100
1101=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc'
1102--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc 1970-01-01 00:00:00 +0000
1103+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.inc 2013-12-17 07:03:32 +0000
1104@@ -0,0 +1,41 @@
1105+SET SESSION query_response_time_exec_time_debug=100000;
1106+
1107+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1108+EVAL SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=$base;
1109+SET GLOBAL query_response_time_flush=1;
1110+# Following two queries check works of FLUSH and
1111+# respecting of "QUERY_RESPONSE_TIME_STATS" variable (see launchpad bug #855312)
1112+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1113+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1114+
1115+SET SESSION query_response_time_exec_time_debug=310000; SELECT 1;
1116+SET SESSION query_response_time_exec_time_debug=320000; SELECT 1;
1117+SET SESSION query_response_time_exec_time_debug=330000; SELECT 1;
1118+SET SESSION query_response_time_exec_time_debug=340000; SELECT 1;
1119+SET SESSION query_response_time_exec_time_debug=350000; SELECT 1;
1120+SET SESSION query_response_time_exec_time_debug=360000; SELECT 1;
1121+SET SESSION query_response_time_exec_time_debug=370000; SELECT 1;
1122+SET SESSION query_response_time_exec_time_debug=380000; SELECT 1;
1123+SET SESSION query_response_time_exec_time_debug=390000; SELECT 1;
1124+SET SESSION query_response_time_exec_time_debug=400000; SELECT 1;
1125+SET SESSION query_response_time_exec_time_debug=1100000; SELECT 1;
1126+SET SESSION query_response_time_exec_time_debug=1200000; SELECT 1;
1127+SET SESSION query_response_time_exec_time_debug=1300000; SELECT 1;
1128+SET SESSION query_response_time_exec_time_debug=1500000; SELECT 1;
1129+SET SESSION query_response_time_exec_time_debug=1400000; SELECT 1;
1130+SET SESSION query_response_time_exec_time_debug=500000; SELECT 1;
1131+SET SESSION query_response_time_exec_time_debug=2100000; SELECT 1;
1132+SET SESSION query_response_time_exec_time_debug=2300000; SELECT 1;
1133+SET SESSION query_response_time_exec_time_debug=2500000; SELECT 1;
1134+SET SESSION query_response_time_exec_time_debug=3100000; SELECT 1;
1135+SET SESSION query_response_time_exec_time_debug=4100000; SELECT 1;
1136+SET SESSION query_response_time_exec_time_debug=5100000; SELECT 1;
1137+
1138+SET SESSION query_response_time_exec_time_debug=100000;
1139+
1140+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1141+
1142+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1143+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1144+
1145+SET SESSION query_response_time_exec_time_debug=default;
1146
1147=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result'
1148--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result 1970-01-01 00:00:00 +0000
1149+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.result 2013-12-17 07:03:32 +0000
1150@@ -0,0 +1,1003 @@
1151+SET SESSION query_response_time_exec_time_debug=100000;
1152+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1153+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1;
1154+Warnings:
1155+Warning 1292 Truncated incorrect query_response_time_range_base value: '1'
1156+SET GLOBAL query_response_time_flush=1;
1157+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1158+TIME COUNT TOTAL
1159+ 0.000001 0 0.000000
1160+ 0.000003 0 0.000000
1161+ 0.000007 0 0.000000
1162+ 0.000015 0 0.000000
1163+ 0.000030 0 0.000000
1164+ 0.000061 0 0.000000
1165+ 0.000122 0 0.000000
1166+ 0.000244 0 0.000000
1167+ 0.000488 0 0.000000
1168+ 0.000976 0 0.000000
1169+ 0.001953 0 0.000000
1170+ 0.003906 0 0.000000
1171+ 0.007812 0 0.000000
1172+ 0.015625 0 0.000000
1173+ 0.031250 0 0.000000
1174+ 0.062500 0 0.000000
1175+ 0.125000 0 0.000000
1176+ 0.250000 0 0.000000
1177+ 0.500000 0 0.000000
1178+ 1.000000 0 0.000000
1179+ 2.000000 0 0.000000
1180+ 4.000000 0 0.000000
1181+ 8.000000 0 0.000000
1182+ 16.000000 0 0.000000
1183+ 32.000000 0 0.000000
1184+ 64.000000 0 0.000000
1185+ 128.000000 0 0.000000
1186+ 256.000000 0 0.000000
1187+ 512.000000 0 0.000000
1188+ 1024.000000 0 0.000000
1189+ 2048.000000 0 0.000000
1190+ 4096.000000 0 0.000000
1191+ 8192.000000 0 0.000000
1192+ 16384.000000 0 0.000000
1193+ 32768.000000 0 0.000000
1194+ 65536.000000 0 0.000000
1195+ 131072.000000 0 0.000000
1196+ 262144.000000 0 0.000000
1197+ 524288.000000 0 0.000000
1198+1048576.000000 0 0.000000
1199+2097152.000000 0 0.000000
1200+4194304.000000 0 0.000000
1201+8388608.000000 0 0.000000
1202+TOO LONG 0 TOO LONG
1203+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1204+SET SESSION query_response_time_exec_time_debug=310000;
1205+SELECT 1;
1206+1
1207+1
1208+SET SESSION query_response_time_exec_time_debug=320000;
1209+SELECT 1;
1210+1
1211+1
1212+SET SESSION query_response_time_exec_time_debug=330000;
1213+SELECT 1;
1214+1
1215+1
1216+SET SESSION query_response_time_exec_time_debug=340000;
1217+SELECT 1;
1218+1
1219+1
1220+SET SESSION query_response_time_exec_time_debug=350000;
1221+SELECT 1;
1222+1
1223+1
1224+SET SESSION query_response_time_exec_time_debug=360000;
1225+SELECT 1;
1226+1
1227+1
1228+SET SESSION query_response_time_exec_time_debug=370000;
1229+SELECT 1;
1230+1
1231+1
1232+SET SESSION query_response_time_exec_time_debug=380000;
1233+SELECT 1;
1234+1
1235+1
1236+SET SESSION query_response_time_exec_time_debug=390000;
1237+SELECT 1;
1238+1
1239+1
1240+SET SESSION query_response_time_exec_time_debug=400000;
1241+SELECT 1;
1242+1
1243+1
1244+SET SESSION query_response_time_exec_time_debug=1100000;
1245+SELECT 1;
1246+1
1247+1
1248+SET SESSION query_response_time_exec_time_debug=1200000;
1249+SELECT 1;
1250+1
1251+1
1252+SET SESSION query_response_time_exec_time_debug=1300000;
1253+SELECT 1;
1254+1
1255+1
1256+SET SESSION query_response_time_exec_time_debug=1500000;
1257+SELECT 1;
1258+1
1259+1
1260+SET SESSION query_response_time_exec_time_debug=1400000;
1261+SELECT 1;
1262+1
1263+1
1264+SET SESSION query_response_time_exec_time_debug=500000;
1265+SELECT 1;
1266+1
1267+1
1268+SET SESSION query_response_time_exec_time_debug=2100000;
1269+SELECT 1;
1270+1
1271+1
1272+SET SESSION query_response_time_exec_time_debug=2300000;
1273+SELECT 1;
1274+1
1275+1
1276+SET SESSION query_response_time_exec_time_debug=2500000;
1277+SELECT 1;
1278+1
1279+1
1280+SET SESSION query_response_time_exec_time_debug=3100000;
1281+SELECT 1;
1282+1
1283+1
1284+SET SESSION query_response_time_exec_time_debug=4100000;
1285+SELECT 1;
1286+1
1287+1
1288+SET SESSION query_response_time_exec_time_debug=5100000;
1289+SELECT 1;
1290+1
1291+1
1292+SET SESSION query_response_time_exec_time_debug=100000;
1293+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1294+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1295+Variable_name Value
1296+query_response_time_range_base 2
1297+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1298+TIME COUNT TOTAL
1299+ 0.000001 24 0.000000
1300+ 0.000003 0 0.000000
1301+ 0.000007 0 0.000000
1302+ 0.000015 0 0.000000
1303+ 0.000030 0 0.000000
1304+ 0.000061 0 0.000000
1305+ 0.000122 0 0.000000
1306+ 0.000244 0 0.000000
1307+ 0.000488 0 0.000000
1308+ 0.000976 0 0.000000
1309+ 0.001953 0 0.000000
1310+ 0.003906 0 0.000000
1311+ 0.007812 0 0.000000
1312+ 0.015625 0 0.000000
1313+ 0.031250 0 0.000000
1314+ 0.062500 0 0.000000
1315+ 0.125000 0 0.000000
1316+ 0.250000 0 0.000000
1317+ 0.500000 10 3.550000
1318+ 1.000000 1 0.500000
1319+ 2.000000 5 6.500000
1320+ 4.000000 4 10.000000
1321+ 8.000000 2 9.200000
1322+ 16.000000 0 0.000000
1323+ 32.000000 0 0.000000
1324+ 64.000000 0 0.000000
1325+ 128.000000 0 0.000000
1326+ 256.000000 0 0.000000
1327+ 512.000000 0 0.000000
1328+ 1024.000000 0 0.000000
1329+ 2048.000000 0 0.000000
1330+ 4096.000000 0 0.000000
1331+ 8192.000000 0 0.000000
1332+ 16384.000000 0 0.000000
1333+ 32768.000000 0 0.000000
1334+ 65536.000000 0 0.000000
1335+ 131072.000000 0 0.000000
1336+ 262144.000000 0 0.000000
1337+ 524288.000000 0 0.000000
1338+1048576.000000 0 0.000000
1339+2097152.000000 0 0.000000
1340+4194304.000000 0 0.000000
1341+8388608.000000 0 0.000000
1342+TOO LONG 0 TOO LONG
1343+SET SESSION query_response_time_exec_time_debug=default;
1344+SET SESSION query_response_time_exec_time_debug=100000;
1345+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1346+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=2;
1347+SET GLOBAL query_response_time_flush=1;
1348+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1349+TIME COUNT TOTAL
1350+ 0.000001 0 0.000000
1351+ 0.000003 0 0.000000
1352+ 0.000007 0 0.000000
1353+ 0.000015 0 0.000000
1354+ 0.000030 0 0.000000
1355+ 0.000061 0 0.000000
1356+ 0.000122 0 0.000000
1357+ 0.000244 0 0.000000
1358+ 0.000488 0 0.000000
1359+ 0.000976 0 0.000000
1360+ 0.001953 0 0.000000
1361+ 0.003906 0 0.000000
1362+ 0.007812 0 0.000000
1363+ 0.015625 0 0.000000
1364+ 0.031250 0 0.000000
1365+ 0.062500 0 0.000000
1366+ 0.125000 0 0.000000
1367+ 0.250000 0 0.000000
1368+ 0.500000 0 0.000000
1369+ 1.000000 0 0.000000
1370+ 2.000000 0 0.000000
1371+ 4.000000 0 0.000000
1372+ 8.000000 0 0.000000
1373+ 16.000000 0 0.000000
1374+ 32.000000 0 0.000000
1375+ 64.000000 0 0.000000
1376+ 128.000000 0 0.000000
1377+ 256.000000 0 0.000000
1378+ 512.000000 0 0.000000
1379+ 1024.000000 0 0.000000
1380+ 2048.000000 0 0.000000
1381+ 4096.000000 0 0.000000
1382+ 8192.000000 0 0.000000
1383+ 16384.000000 0 0.000000
1384+ 32768.000000 0 0.000000
1385+ 65536.000000 0 0.000000
1386+ 131072.000000 0 0.000000
1387+ 262144.000000 0 0.000000
1388+ 524288.000000 0 0.000000
1389+1048576.000000 0 0.000000
1390+2097152.000000 0 0.000000
1391+4194304.000000 0 0.000000
1392+8388608.000000 0 0.000000
1393+TOO LONG 0 TOO LONG
1394+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1395+SET SESSION query_response_time_exec_time_debug=310000;
1396+SELECT 1;
1397+1
1398+1
1399+SET SESSION query_response_time_exec_time_debug=320000;
1400+SELECT 1;
1401+1
1402+1
1403+SET SESSION query_response_time_exec_time_debug=330000;
1404+SELECT 1;
1405+1
1406+1
1407+SET SESSION query_response_time_exec_time_debug=340000;
1408+SELECT 1;
1409+1
1410+1
1411+SET SESSION query_response_time_exec_time_debug=350000;
1412+SELECT 1;
1413+1
1414+1
1415+SET SESSION query_response_time_exec_time_debug=360000;
1416+SELECT 1;
1417+1
1418+1
1419+SET SESSION query_response_time_exec_time_debug=370000;
1420+SELECT 1;
1421+1
1422+1
1423+SET SESSION query_response_time_exec_time_debug=380000;
1424+SELECT 1;
1425+1
1426+1
1427+SET SESSION query_response_time_exec_time_debug=390000;
1428+SELECT 1;
1429+1
1430+1
1431+SET SESSION query_response_time_exec_time_debug=400000;
1432+SELECT 1;
1433+1
1434+1
1435+SET SESSION query_response_time_exec_time_debug=1100000;
1436+SELECT 1;
1437+1
1438+1
1439+SET SESSION query_response_time_exec_time_debug=1200000;
1440+SELECT 1;
1441+1
1442+1
1443+SET SESSION query_response_time_exec_time_debug=1300000;
1444+SELECT 1;
1445+1
1446+1
1447+SET SESSION query_response_time_exec_time_debug=1500000;
1448+SELECT 1;
1449+1
1450+1
1451+SET SESSION query_response_time_exec_time_debug=1400000;
1452+SELECT 1;
1453+1
1454+1
1455+SET SESSION query_response_time_exec_time_debug=500000;
1456+SELECT 1;
1457+1
1458+1
1459+SET SESSION query_response_time_exec_time_debug=2100000;
1460+SELECT 1;
1461+1
1462+1
1463+SET SESSION query_response_time_exec_time_debug=2300000;
1464+SELECT 1;
1465+1
1466+1
1467+SET SESSION query_response_time_exec_time_debug=2500000;
1468+SELECT 1;
1469+1
1470+1
1471+SET SESSION query_response_time_exec_time_debug=3100000;
1472+SELECT 1;
1473+1
1474+1
1475+SET SESSION query_response_time_exec_time_debug=4100000;
1476+SELECT 1;
1477+1
1478+1
1479+SET SESSION query_response_time_exec_time_debug=5100000;
1480+SELECT 1;
1481+1
1482+1
1483+SET SESSION query_response_time_exec_time_debug=100000;
1484+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1485+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1486+Variable_name Value
1487+query_response_time_range_base 2
1488+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1489+TIME COUNT TOTAL
1490+ 0.000001 24 0.000000
1491+ 0.000003 0 0.000000
1492+ 0.000007 0 0.000000
1493+ 0.000015 0 0.000000
1494+ 0.000030 0 0.000000
1495+ 0.000061 0 0.000000
1496+ 0.000122 0 0.000000
1497+ 0.000244 0 0.000000
1498+ 0.000488 0 0.000000
1499+ 0.000976 0 0.000000
1500+ 0.001953 0 0.000000
1501+ 0.003906 0 0.000000
1502+ 0.007812 0 0.000000
1503+ 0.015625 0 0.000000
1504+ 0.031250 0 0.000000
1505+ 0.062500 0 0.000000
1506+ 0.125000 0 0.000000
1507+ 0.250000 0 0.000000
1508+ 0.500000 10 3.550000
1509+ 1.000000 1 0.500000
1510+ 2.000000 5 6.500000
1511+ 4.000000 4 10.000000
1512+ 8.000000 2 9.200000
1513+ 16.000000 0 0.000000
1514+ 32.000000 0 0.000000
1515+ 64.000000 0 0.000000
1516+ 128.000000 0 0.000000
1517+ 256.000000 0 0.000000
1518+ 512.000000 0 0.000000
1519+ 1024.000000 0 0.000000
1520+ 2048.000000 0 0.000000
1521+ 4096.000000 0 0.000000
1522+ 8192.000000 0 0.000000
1523+ 16384.000000 0 0.000000
1524+ 32768.000000 0 0.000000
1525+ 65536.000000 0 0.000000
1526+ 131072.000000 0 0.000000
1527+ 262144.000000 0 0.000000
1528+ 524288.000000 0 0.000000
1529+1048576.000000 0 0.000000
1530+2097152.000000 0 0.000000
1531+4194304.000000 0 0.000000
1532+8388608.000000 0 0.000000
1533+TOO LONG 0 TOO LONG
1534+SET SESSION query_response_time_exec_time_debug=default;
1535+SET SESSION query_response_time_exec_time_debug=100000;
1536+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1537+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=10;
1538+SET GLOBAL query_response_time_flush=1;
1539+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1540+TIME COUNT TOTAL
1541+ 0.000001 0 0.000000
1542+ 0.000010 0 0.000000
1543+ 0.000100 0 0.000000
1544+ 0.001000 0 0.000000
1545+ 0.010000 0 0.000000
1546+ 0.100000 0 0.000000
1547+ 1.000000 0 0.000000
1548+ 10.000000 0 0.000000
1549+ 100.000000 0 0.000000
1550+ 1000.000000 0 0.000000
1551+ 10000.000000 0 0.000000
1552+ 100000.000000 0 0.000000
1553+1000000.000000 0 0.000000
1554+TOO LONG 0 TOO LONG
1555+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1556+SET SESSION query_response_time_exec_time_debug=310000;
1557+SELECT 1;
1558+1
1559+1
1560+SET SESSION query_response_time_exec_time_debug=320000;
1561+SELECT 1;
1562+1
1563+1
1564+SET SESSION query_response_time_exec_time_debug=330000;
1565+SELECT 1;
1566+1
1567+1
1568+SET SESSION query_response_time_exec_time_debug=340000;
1569+SELECT 1;
1570+1
1571+1
1572+SET SESSION query_response_time_exec_time_debug=350000;
1573+SELECT 1;
1574+1
1575+1
1576+SET SESSION query_response_time_exec_time_debug=360000;
1577+SELECT 1;
1578+1
1579+1
1580+SET SESSION query_response_time_exec_time_debug=370000;
1581+SELECT 1;
1582+1
1583+1
1584+SET SESSION query_response_time_exec_time_debug=380000;
1585+SELECT 1;
1586+1
1587+1
1588+SET SESSION query_response_time_exec_time_debug=390000;
1589+SELECT 1;
1590+1
1591+1
1592+SET SESSION query_response_time_exec_time_debug=400000;
1593+SELECT 1;
1594+1
1595+1
1596+SET SESSION query_response_time_exec_time_debug=1100000;
1597+SELECT 1;
1598+1
1599+1
1600+SET SESSION query_response_time_exec_time_debug=1200000;
1601+SELECT 1;
1602+1
1603+1
1604+SET SESSION query_response_time_exec_time_debug=1300000;
1605+SELECT 1;
1606+1
1607+1
1608+SET SESSION query_response_time_exec_time_debug=1500000;
1609+SELECT 1;
1610+1
1611+1
1612+SET SESSION query_response_time_exec_time_debug=1400000;
1613+SELECT 1;
1614+1
1615+1
1616+SET SESSION query_response_time_exec_time_debug=500000;
1617+SELECT 1;
1618+1
1619+1
1620+SET SESSION query_response_time_exec_time_debug=2100000;
1621+SELECT 1;
1622+1
1623+1
1624+SET SESSION query_response_time_exec_time_debug=2300000;
1625+SELECT 1;
1626+1
1627+1
1628+SET SESSION query_response_time_exec_time_debug=2500000;
1629+SELECT 1;
1630+1
1631+1
1632+SET SESSION query_response_time_exec_time_debug=3100000;
1633+SELECT 1;
1634+1
1635+1
1636+SET SESSION query_response_time_exec_time_debug=4100000;
1637+SELECT 1;
1638+1
1639+1
1640+SET SESSION query_response_time_exec_time_debug=5100000;
1641+SELECT 1;
1642+1
1643+1
1644+SET SESSION query_response_time_exec_time_debug=100000;
1645+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1646+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1647+Variable_name Value
1648+query_response_time_range_base 10
1649+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1650+TIME COUNT TOTAL
1651+ 0.000001 24 0.000000
1652+ 0.000010 0 0.000000
1653+ 0.000100 0 0.000000
1654+ 0.001000 0 0.000000
1655+ 0.010000 0 0.000000
1656+ 0.100000 0 0.000000
1657+ 1.000000 11 4.050000
1658+ 10.000000 11 25.700000
1659+ 100.000000 0 0.000000
1660+ 1000.000000 0 0.000000
1661+ 10000.000000 0 0.000000
1662+ 100000.000000 0 0.000000
1663+1000000.000000 0 0.000000
1664+TOO LONG 0 TOO LONG
1665+SET SESSION query_response_time_exec_time_debug=default;
1666+SET SESSION query_response_time_exec_time_debug=100000;
1667+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1668+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=7;
1669+SET GLOBAL query_response_time_flush=1;
1670+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1671+TIME COUNT TOTAL
1672+ 0.000001 0 0.000000
1673+ 0.000008 0 0.000000
1674+ 0.000059 0 0.000000
1675+ 0.000416 0 0.000000
1676+ 0.002915 0 0.000000
1677+ 0.020408 0 0.000000
1678+ 0.142857 0 0.000000
1679+ 1.000000 0 0.000000
1680+ 7.000000 0 0.000000
1681+ 49.000000 0 0.000000
1682+ 343.000000 0 0.000000
1683+ 2401.000000 0 0.000000
1684+ 16807.000000 0 0.000000
1685+ 117649.000000 0 0.000000
1686+ 823543.000000 0 0.000000
1687+5764801.000000 0 0.000000
1688+TOO LONG 0 TOO LONG
1689+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1690+SET SESSION query_response_time_exec_time_debug=310000;
1691+SELECT 1;
1692+1
1693+1
1694+SET SESSION query_response_time_exec_time_debug=320000;
1695+SELECT 1;
1696+1
1697+1
1698+SET SESSION query_response_time_exec_time_debug=330000;
1699+SELECT 1;
1700+1
1701+1
1702+SET SESSION query_response_time_exec_time_debug=340000;
1703+SELECT 1;
1704+1
1705+1
1706+SET SESSION query_response_time_exec_time_debug=350000;
1707+SELECT 1;
1708+1
1709+1
1710+SET SESSION query_response_time_exec_time_debug=360000;
1711+SELECT 1;
1712+1
1713+1
1714+SET SESSION query_response_time_exec_time_debug=370000;
1715+SELECT 1;
1716+1
1717+1
1718+SET SESSION query_response_time_exec_time_debug=380000;
1719+SELECT 1;
1720+1
1721+1
1722+SET SESSION query_response_time_exec_time_debug=390000;
1723+SELECT 1;
1724+1
1725+1
1726+SET SESSION query_response_time_exec_time_debug=400000;
1727+SELECT 1;
1728+1
1729+1
1730+SET SESSION query_response_time_exec_time_debug=1100000;
1731+SELECT 1;
1732+1
1733+1
1734+SET SESSION query_response_time_exec_time_debug=1200000;
1735+SELECT 1;
1736+1
1737+1
1738+SET SESSION query_response_time_exec_time_debug=1300000;
1739+SELECT 1;
1740+1
1741+1
1742+SET SESSION query_response_time_exec_time_debug=1500000;
1743+SELECT 1;
1744+1
1745+1
1746+SET SESSION query_response_time_exec_time_debug=1400000;
1747+SELECT 1;
1748+1
1749+1
1750+SET SESSION query_response_time_exec_time_debug=500000;
1751+SELECT 1;
1752+1
1753+1
1754+SET SESSION query_response_time_exec_time_debug=2100000;
1755+SELECT 1;
1756+1
1757+1
1758+SET SESSION query_response_time_exec_time_debug=2300000;
1759+SELECT 1;
1760+1
1761+1
1762+SET SESSION query_response_time_exec_time_debug=2500000;
1763+SELECT 1;
1764+1
1765+1
1766+SET SESSION query_response_time_exec_time_debug=3100000;
1767+SELECT 1;
1768+1
1769+1
1770+SET SESSION query_response_time_exec_time_debug=4100000;
1771+SELECT 1;
1772+1
1773+1
1774+SET SESSION query_response_time_exec_time_debug=5100000;
1775+SELECT 1;
1776+1
1777+1
1778+SET SESSION query_response_time_exec_time_debug=100000;
1779+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1780+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1781+Variable_name Value
1782+query_response_time_range_base 7
1783+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1784+TIME COUNT TOTAL
1785+ 0.000001 24 0.000000
1786+ 0.000008 0 0.000000
1787+ 0.000059 0 0.000000
1788+ 0.000416 0 0.000000
1789+ 0.002915 0 0.000000
1790+ 0.020408 0 0.000000
1791+ 0.142857 0 0.000000
1792+ 1.000000 11 4.050000
1793+ 7.000000 11 25.700000
1794+ 49.000000 0 0.000000
1795+ 343.000000 0 0.000000
1796+ 2401.000000 0 0.000000
1797+ 16807.000000 0 0.000000
1798+ 117649.000000 0 0.000000
1799+ 823543.000000 0 0.000000
1800+5764801.000000 0 0.000000
1801+TOO LONG 0 TOO LONG
1802+SET SESSION query_response_time_exec_time_debug=default;
1803+SET SESSION query_response_time_exec_time_debug=100000;
1804+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1805+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=156;
1806+SET GLOBAL query_response_time_flush=1;
1807+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1808+TIME COUNT TOTAL
1809+ 0.000041 0 0.000000
1810+ 0.006410 0 0.000000
1811+ 1.000000 0 0.000000
1812+ 156.000000 0 0.000000
1813+ 24336.000000 0 0.000000
1814+3796416.000000 0 0.000000
1815+TOO LONG 0 TOO LONG
1816+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1817+SET SESSION query_response_time_exec_time_debug=310000;
1818+SELECT 1;
1819+1
1820+1
1821+SET SESSION query_response_time_exec_time_debug=320000;
1822+SELECT 1;
1823+1
1824+1
1825+SET SESSION query_response_time_exec_time_debug=330000;
1826+SELECT 1;
1827+1
1828+1
1829+SET SESSION query_response_time_exec_time_debug=340000;
1830+SELECT 1;
1831+1
1832+1
1833+SET SESSION query_response_time_exec_time_debug=350000;
1834+SELECT 1;
1835+1
1836+1
1837+SET SESSION query_response_time_exec_time_debug=360000;
1838+SELECT 1;
1839+1
1840+1
1841+SET SESSION query_response_time_exec_time_debug=370000;
1842+SELECT 1;
1843+1
1844+1
1845+SET SESSION query_response_time_exec_time_debug=380000;
1846+SELECT 1;
1847+1
1848+1
1849+SET SESSION query_response_time_exec_time_debug=390000;
1850+SELECT 1;
1851+1
1852+1
1853+SET SESSION query_response_time_exec_time_debug=400000;
1854+SELECT 1;
1855+1
1856+1
1857+SET SESSION query_response_time_exec_time_debug=1100000;
1858+SELECT 1;
1859+1
1860+1
1861+SET SESSION query_response_time_exec_time_debug=1200000;
1862+SELECT 1;
1863+1
1864+1
1865+SET SESSION query_response_time_exec_time_debug=1300000;
1866+SELECT 1;
1867+1
1868+1
1869+SET SESSION query_response_time_exec_time_debug=1500000;
1870+SELECT 1;
1871+1
1872+1
1873+SET SESSION query_response_time_exec_time_debug=1400000;
1874+SELECT 1;
1875+1
1876+1
1877+SET SESSION query_response_time_exec_time_debug=500000;
1878+SELECT 1;
1879+1
1880+1
1881+SET SESSION query_response_time_exec_time_debug=2100000;
1882+SELECT 1;
1883+1
1884+1
1885+SET SESSION query_response_time_exec_time_debug=2300000;
1886+SELECT 1;
1887+1
1888+1
1889+SET SESSION query_response_time_exec_time_debug=2500000;
1890+SELECT 1;
1891+1
1892+1
1893+SET SESSION query_response_time_exec_time_debug=3100000;
1894+SELECT 1;
1895+1
1896+1
1897+SET SESSION query_response_time_exec_time_debug=4100000;
1898+SELECT 1;
1899+1
1900+1
1901+SET SESSION query_response_time_exec_time_debug=5100000;
1902+SELECT 1;
1903+1
1904+1
1905+SET SESSION query_response_time_exec_time_debug=100000;
1906+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1907+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
1908+Variable_name Value
1909+query_response_time_range_base 156
1910+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1911+TIME COUNT TOTAL
1912+ 0.000041 24 0.000000
1913+ 0.006410 0 0.000000
1914+ 1.000000 11 4.050000
1915+ 156.000000 11 25.700000
1916+ 24336.000000 0 0.000000
1917+3796416.000000 0 0.000000
1918+TOO LONG 0 TOO LONG
1919+SET SESSION query_response_time_exec_time_debug=default;
1920+SET SESSION query_response_time_exec_time_debug=100000;
1921+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
1922+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1000;
1923+SET GLOBAL query_response_time_flush=1;
1924+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
1925+TIME COUNT TOTAL
1926+ 0.000001 0 0.000000
1927+ 0.001000 0 0.000000
1928+ 1.000000 0 0.000000
1929+ 1000.000000 0 0.000000
1930+1000000.000000 0 0.000000
1931+TOO LONG 0 TOO LONG
1932+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
1933+SET SESSION query_response_time_exec_time_debug=310000;
1934+SELECT 1;
1935+1
1936+1
1937+SET SESSION query_response_time_exec_time_debug=320000;
1938+SELECT 1;
1939+1
1940+1
1941+SET SESSION query_response_time_exec_time_debug=330000;
1942+SELECT 1;
1943+1
1944+1
1945+SET SESSION query_response_time_exec_time_debug=340000;
1946+SELECT 1;
1947+1
1948+1
1949+SET SESSION query_response_time_exec_time_debug=350000;
1950+SELECT 1;
1951+1
1952+1
1953+SET SESSION query_response_time_exec_time_debug=360000;
1954+SELECT 1;
1955+1
1956+1
1957+SET SESSION query_response_time_exec_time_debug=370000;
1958+SELECT 1;
1959+1
1960+1
1961+SET SESSION query_response_time_exec_time_debug=380000;
1962+SELECT 1;
1963+1
1964+1
1965+SET SESSION query_response_time_exec_time_debug=390000;
1966+SELECT 1;
1967+1
1968+1
1969+SET SESSION query_response_time_exec_time_debug=400000;
1970+SELECT 1;
1971+1
1972+1
1973+SET SESSION query_response_time_exec_time_debug=1100000;
1974+SELECT 1;
1975+1
1976+1
1977+SET SESSION query_response_time_exec_time_debug=1200000;
1978+SELECT 1;
1979+1
1980+1
1981+SET SESSION query_response_time_exec_time_debug=1300000;
1982+SELECT 1;
1983+1
1984+1
1985+SET SESSION query_response_time_exec_time_debug=1500000;
1986+SELECT 1;
1987+1
1988+1
1989+SET SESSION query_response_time_exec_time_debug=1400000;
1990+SELECT 1;
1991+1
1992+1
1993+SET SESSION query_response_time_exec_time_debug=500000;
1994+SELECT 1;
1995+1
1996+1
1997+SET SESSION query_response_time_exec_time_debug=2100000;
1998+SELECT 1;
1999+1
2000+1
2001+SET SESSION query_response_time_exec_time_debug=2300000;
2002+SELECT 1;
2003+1
2004+1
2005+SET SESSION query_response_time_exec_time_debug=2500000;
2006+SELECT 1;
2007+1
2008+1
2009+SET SESSION query_response_time_exec_time_debug=3100000;
2010+SELECT 1;
2011+1
2012+1
2013+SET SESSION query_response_time_exec_time_debug=4100000;
2014+SELECT 1;
2015+1
2016+1
2017+SET SESSION query_response_time_exec_time_debug=5100000;
2018+SELECT 1;
2019+1
2020+1
2021+SET SESSION query_response_time_exec_time_debug=100000;
2022+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
2023+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
2024+Variable_name Value
2025+query_response_time_range_base 1000
2026+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
2027+TIME COUNT TOTAL
2028+ 0.000001 24 0.000000
2029+ 0.001000 0 0.000000
2030+ 1.000000 11 4.050000
2031+ 1000.000000 11 25.700000
2032+1000000.000000 0 0.000000
2033+TOO LONG 0 TOO LONG
2034+SET SESSION query_response_time_exec_time_debug=default;
2035+SET SESSION query_response_time_exec_time_debug=100000;
2036+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
2037+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1001;
2038+Warnings:
2039+Warning 1292 Truncated incorrect query_response_time_range_base value: '1001'
2040+SET GLOBAL query_response_time_flush=1;
2041+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
2042+TIME COUNT TOTAL
2043+ 0.000001 0 0.000000
2044+ 0.001000 0 0.000000
2045+ 1.000000 0 0.000000
2046+ 1000.000000 0 0.000000
2047+1000000.000000 0 0.000000
2048+TOO LONG 0 TOO LONG
2049+SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
2050+SET SESSION query_response_time_exec_time_debug=310000;
2051+SELECT 1;
2052+1
2053+1
2054+SET SESSION query_response_time_exec_time_debug=320000;
2055+SELECT 1;
2056+1
2057+1
2058+SET SESSION query_response_time_exec_time_debug=330000;
2059+SELECT 1;
2060+1
2061+1
2062+SET SESSION query_response_time_exec_time_debug=340000;
2063+SELECT 1;
2064+1
2065+1
2066+SET SESSION query_response_time_exec_time_debug=350000;
2067+SELECT 1;
2068+1
2069+1
2070+SET SESSION query_response_time_exec_time_debug=360000;
2071+SELECT 1;
2072+1
2073+1
2074+SET SESSION query_response_time_exec_time_debug=370000;
2075+SELECT 1;
2076+1
2077+1
2078+SET SESSION query_response_time_exec_time_debug=380000;
2079+SELECT 1;
2080+1
2081+1
2082+SET SESSION query_response_time_exec_time_debug=390000;
2083+SELECT 1;
2084+1
2085+1
2086+SET SESSION query_response_time_exec_time_debug=400000;
2087+SELECT 1;
2088+1
2089+1
2090+SET SESSION query_response_time_exec_time_debug=1100000;
2091+SELECT 1;
2092+1
2093+1
2094+SET SESSION query_response_time_exec_time_debug=1200000;
2095+SELECT 1;
2096+1
2097+1
2098+SET SESSION query_response_time_exec_time_debug=1300000;
2099+SELECT 1;
2100+1
2101+1
2102+SET SESSION query_response_time_exec_time_debug=1500000;
2103+SELECT 1;
2104+1
2105+1
2106+SET SESSION query_response_time_exec_time_debug=1400000;
2107+SELECT 1;
2108+1
2109+1
2110+SET SESSION query_response_time_exec_time_debug=500000;
2111+SELECT 1;
2112+1
2113+1
2114+SET SESSION query_response_time_exec_time_debug=2100000;
2115+SELECT 1;
2116+1
2117+1
2118+SET SESSION query_response_time_exec_time_debug=2300000;
2119+SELECT 1;
2120+1
2121+1
2122+SET SESSION query_response_time_exec_time_debug=2500000;
2123+SELECT 1;
2124+1
2125+1
2126+SET SESSION query_response_time_exec_time_debug=3100000;
2127+SELECT 1;
2128+1
2129+1
2130+SET SESSION query_response_time_exec_time_debug=4100000;
2131+SELECT 1;
2132+1
2133+1
2134+SET SESSION query_response_time_exec_time_debug=5100000;
2135+SELECT 1;
2136+1
2137+1
2138+SET SESSION query_response_time_exec_time_debug=100000;
2139+SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
2140+SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
2141+Variable_name Value
2142+query_response_time_range_base 1000
2143+SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
2144+TIME COUNT TOTAL
2145+ 0.000001 24 0.000000
2146+ 0.001000 0 0.000000
2147+ 1.000000 11 4.050000
2148+ 1000.000000 11 25.700000
2149+1000000.000000 0 0.000000
2150+TOO LONG 0 TOO LONG
2151+SET SESSION query_response_time_exec_time_debug=default;
2152+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
2153+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
2154
2155=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test'
2156--- Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test 1970-01-01 00:00:00 +0000
2157+++ Percona-Server/plugin/query_response_time/tests/mtr/query_response_time.test 2013-12-17 07:03:32 +0000
2158@@ -0,0 +1,28 @@
2159+--source include/have_debug.inc
2160+
2161+# The file with expected results fits only to a run without
2162+# ps-protocol/sp-protocol/cursor-protocol/view-protocol.
2163+if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
2164+ + $VIEW_PROTOCOL > 0`)
2165+{
2166+ --skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
2167+}
2168+
2169+
2170+--let base=1
2171+--source query_response_time.inc
2172+--let base=2
2173+--source query_response_time.inc
2174+--let base=10
2175+--source query_response_time.inc
2176+--let base=7
2177+--source query_response_time.inc
2178+--let base=156
2179+--source query_response_time.inc
2180+--let base=1000
2181+--source query_response_time.inc
2182+--let base=1001
2183+--source query_response_time.inc
2184+
2185+SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
2186+SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
2187
2188=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/suite.opt'
2189--- Percona-Server/plugin/query_response_time/tests/mtr/suite.opt 1970-01-01 00:00:00 +0000
2190+++ Percona-Server/plugin/query_response_time/tests/mtr/suite.opt 2013-12-17 07:03:32 +0000
2191@@ -0,0 +1,1 @@
2192+$PLUGIN_QUERY_RESPONSE_TIME_OPT $PLUGIN_QUERY_RESPONSE_TIME_LOAD
2193
2194=== added file 'Percona-Server/plugin/query_response_time/tests/mtr/suite.pm'
2195--- Percona-Server/plugin/query_response_time/tests/mtr/suite.pm 1970-01-01 00:00:00 +0000
2196+++ Percona-Server/plugin/query_response_time/tests/mtr/suite.pm 2013-12-17 07:03:32 +0000
2197@@ -0,0 +1,12 @@
2198+package My::Suite::Query_response_time;
2199+
2200+@ISA = qw(My::Suite);
2201+
2202+return "No QUERY_RESPONSE_TIME plugin" unless
2203+ $ENV{QUERY_RESPONSE_TIME_SO} or
2204+ $::mysqld_variables{'query-response-time'} eq "ON";
2205+
2206+return "Not run for embedded server" if $::opt_embedded_server;
2207+
2208+bless { };
2209+
2210
2211=== modified file 'Percona-Server/sql/sp_instr.cc'
2212--- Percona-Server/sql/sp_instr.cc 2013-12-05 17:23:10 +0000
2213+++ Percona-Server/sql/sp_instr.cc 2013-12-17 07:03:32 +0000
2214@@ -27,6 +27,7 @@
2215 #include "sql_parse.h" // check_table_access
2216 #include "sql_prepare.h" // reinit_stmt_before_use
2217 #include "transaction.h" // trans_commit_stmt
2218+#include "sql_audit.h"
2219
2220 #include <algorithm>
2221
2222@@ -818,6 +819,11 @@
2223
2224 query_cache_end_of_result(thd);
2225
2226+ mysql_audit_general(thd, MYSQL_AUDIT_GENERAL_STATUS,
2227+ thd->get_stmt_da()->is_error() ?
2228+ thd->get_stmt_da()->sql_errno() : 0,
2229+ command_name[COM_QUERY].str);
2230+
2231 if (!rc && unlikely(log_slow_applicable(thd)))
2232 {
2233 /*
2234
2235=== modified file 'Percona-Server/sql/sp_instr.h'
2236--- Percona-Server/sql/sp_instr.h 2013-08-27 11:20:01 +0000
2237+++ Percona-Server/sql/sp_instr.h 2013-12-17 07:03:32 +0000
2238@@ -214,6 +214,10 @@
2239 */
2240 bool validate_lex_and_execute_core(THD *thd, uint *nextp, bool open_tables);
2241
2242+ int get_command() const {
2243+ return m_lex ? m_lex->sql_command : -1;
2244+ }
2245+
2246 private:
2247 /**
2248 Prepare LEX and thread for execution of instruction, if requested open
2249
2250=== modified file 'Percona-Server/sql/sql_class.h'
2251--- Percona-Server/sql/sql_class.h 2013-12-16 08:45:31 +0000
2252+++ Percona-Server/sql/sql_class.h 2013-12-17 07:03:32 +0000
2253@@ -2328,7 +2328,7 @@
2254 struct timeval user_time;
2255 // track down slow pthread_create
2256 ulonglong prior_thr_create_utime, thr_create_utime;
2257- ulonglong start_utime, utime_after_lock;
2258+ ulonglong start_utime, utime_after_lock, utime_after_query;
2259
2260 thr_lock_type update_lock_default;
2261 Delayed_insert *di;
2262@@ -3605,8 +3605,8 @@
2263 */
2264 void update_server_status()
2265 {
2266- ulonglong end_utime_of_query= current_utime();
2267- if (end_utime_of_query > utime_after_lock + variables.long_query_time)
2268+ utime_after_query= current_utime();
2269+ if (utime_after_query > utime_after_lock + variables.long_query_time)
2270 server_status|= SERVER_QUERY_WAS_SLOW;
2271 }
2272 inline ulonglong found_rows(void)

Subscribers

People subscribed via source and target branches