Percona Server moved to https://jira.percona.com/projects/PS

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

  1. 5.6-query_response_time-rw-commands
  2. Merge into 5.6
Proposed by Vlad Lesin
Status: Merged
Approved by: Laurynas Biveinis
Approved revision: no longer in the source branch.
Merged at revision: 735
Proposed branch: lp:~vlad-lesin/percona-server/5.6-query_response_time-rw-commands
Merge into: lp:percona-server/5.6
Diff against target: 1349 lines (+1130/-30)
10 files modified
mysql-test/include/plugin.defs (+1/-1)
plugin/query_response_time/plugin.cc (+60/-2)
plugin/query_response_time/query_response_time.cc (+45/-24)
plugin/query_response_time/query_response_time.h (+8/-1)
plugin/query_response_time/tests/mtr/basic.result (+12/-0)
plugin/query_response_time/tests/mtr/query_response_time-rw-begin.inc (+16/-0)
plugin/query_response_time/tests/mtr/query_response_time-rw-end.inc (+10/-0)
plugin/query_response_time/tests/mtr/query_response_time-rw.result (+765/-0)
plugin/query_response_time/tests/mtr/query_response_time-rw.test (+201/-0)
sql/sp_instr.cc (+12/-2)
To merge this branch: bzr merge lp:~vlad-lesin/percona-server/5.6-query_response_time-rw-commands
Reviewer Review Type Date Requested Status
Laurynas Biveinis (community) Approve
Review via email: mp+243247@code.launchpad.net

Description of the change

This is one more implementation of https://blueprints.launchpad.net/percona-server/+spec/query-response-time-rw blueprint.

The previous implementation was based on MDL(https://code.launchpad.net/~vlad-lesin/percona-server/5.6-query_response_time-rw-MDL), i.e. if restrictive enough MDL is required then the query is treated as 'write'. But this implementation has a number of disadvantages:

- LOCK TABLES t1 WRITE would be blocked by an active FTWRL and thus, would be considered a "write"

- moreover, an INSERT/DELETE/UPDATE with an active LOCK TABLES ... WRITE would _not_ take any MDL locks (that would be handled by LOCK TABLES, which would either block or be blocked by FTWRL), so they would _not_ be considered "write" queries

- EXPLAIN INSERT/UPDATE/DELETE would be a considered a "write" query, though it is obviously not.

- updates to temporary tables will not be considered writes.

The current implementation is based on checking sql command flags. The downside is that queries which are supposed to change data but does not change it are treated as 'write'(for example 'UPDATE ... WHERE condition' when condition is false).

http://jenkins.percona.com/job/percona-server-5.6-param/762/

To post a comment you must log in.
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

    - Please revert rev 689 (its fix is already in the trunk), unlink
      its associated bug, and flatten 690/691 together. While at that,
      a rebase on the current trunk wouldn't hurt neither
    - Please update the blueprint for the read/write difference
      criteria, and what does the command flag criteria mean for the
      end user (including the "downside" from the MP description)
    - IMHO the testcase needs not bother with MyISAM testing, even
      more so as the current implementation is above the SE
      level. That would shorten .result three times
    - Please see the diff comments

review: Needs Fixing
Revision history for this message
Vlad Lesin (vlad-lesin) wrote :

> - IMHO the testcase needs not bother with MyISAM testing, even
> more so as the current implementation is above the SE
> level. That would shorten .result three times
I do not think so because this is regression test and it can be that test results depend on db engine for some implementations, if we change this implementation I want be sure we don't break the functionality for both MyISAM and InnoDB.

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

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

As discussed yesterday on IRC:

- THD::update_server_status uses utime_after_query too
do you know whether updating the field might cause the change of behavior somewhere else?
-
64 - query_response_time_collect(thd->utime_after_query - thd->utime_after_lock);
65 + query_response_time_collect(query_type, thd->utime_after_query - thd->start_utime);
before: utime after lock
after: start utime
why?

review: Needs Information
Revision history for this message
Vlad Lesin (vlad-lesin) wrote :

> As discussed yesterday on IRC:
>
> - THD::update_server_status uses utime_after_query too
> do you know whether updating the field might cause the change of behavior
> somewhere else?
I have checked the code and did not find side effects now. Moreover I ran tests and everything seems ok: http://jenkins.percona.com/view/PS%205.6/job/percona-server-5.6-param/804/ .

> -
> 64 - query_response_time_collect(thd->utime_after_query -
> thd->utime_after_lock);
> 65 + query_response_time_collect(query_type, thd->utime_after_query -
> thd->start_utime);
> before: utime after lock
> after: start utime
> why?

I have changed it for some reason, but unfortunately I don't remember the reason. I tested "utime_after_lock" variant both with regression test and manually with different test cases and it works well so I decided to revert this line.

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) :
review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== modified file 'mysql-test/include/plugin.defs'
--- mysql-test/include/plugin.defs 2014-12-01 15:25:32 +0000
+++ mysql-test/include/plugin.defs 2015-02-04 16:22:40 +0000
@@ -49,5 +49,5 @@
49scalability_metrics plugin/scalability_metrics SCALABILITY_METRICS49scalability_metrics plugin/scalability_metrics SCALABILITY_METRICS
50adt_null plugin/audit_null AUDIT_NULL50adt_null plugin/audit_null AUDIT_NULL
51audit_log plugin/audit_log AUDIT_LOG audit_log51audit_log plugin/audit_log AUDIT_LOG audit_log
52query_response_time plugin/query_response_time PLUGIN_QUERY_RESPONSE_TIME QUERY_RESPONSE_TIME_AUDIT,QUERY_RESPONSE_TIME 52query_response_time plugin/query_response_time PLUGIN_QUERY_RESPONSE_TIME QUERY_RESPONSE_TIME_AUDIT,QUERY_RESPONSE_TIME,QUERY_RESPONSE_TIME_READ,QUERY_RESPONSE_TIME_WRITE
53handlersocket plugin/HandlerSocket-Plugin-for-MySQL HANDLER_SOCKET53handlersocket plugin/HandlerSocket-Plugin-for-MySQL HANDLER_SOCKET
5454
=== modified file 'plugin/query_response_time/plugin.cc'
--- plugin/query_response_time/plugin.cc 2014-09-25 06:33:00 +0000
+++ plugin/query_response_time/plugin.cc 2015-02-04 16:22:40 +0000
@@ -19,6 +19,7 @@
19#include <sql_show.h>19#include <sql_show.h>
20#include <mysql/plugin_audit.h>20#include <mysql/plugin_audit.h>
21#include <sp_instr.h>21#include <sp_instr.h>
22#include <sql_parse.h>
22#include "query_response_time.h"23#include "query_response_time.h"
2324
2425
@@ -130,6 +131,31 @@
130 if (event_general->event_subclass == MYSQL_AUDIT_GENERAL_STATUS &&131 if (event_general->event_subclass == MYSQL_AUDIT_GENERAL_STATUS &&
131 opt_query_response_time_stats)132 opt_query_response_time_stats)
132 {133 {
134 /*
135 Get sql command id of currently executed statement
136 inside of stored function or procedure. If the command is "PREPARE"
137 don't get the statement inside of "PREPARE". If the statement
138 is not inside of stored function or procedure get sql command id
139 of the statement itself.
140 */
141 enum_sql_command sql_command=
142 (
143 thd->lex->sql_command != SQLCOM_PREPARE &&
144 thd->sp_runtime_ctx &&
145 thd->stmt_arena &&
146 ((sp_lex_instr *)thd->stmt_arena)->get_command() >= 0
147 ) ?
148 (enum_sql_command)((sp_lex_instr *)thd->stmt_arena)->get_command() :
149 thd->lex->sql_command;
150 if (sql_command == SQLCOM_EXECUTE)
151 {
152 LEX_STRING *name= &thd->lex->prepared_stmt_name;
153 Statement *stmt=
154 (Statement *)thd->stmt_map.find_by_name(name);
155 sql_command= stmt->lex->sql_command;
156 }
157 QUERY_TYPE query_type=
158 (sql_command_flags[sql_command] & CF_CHANGES_DATA) ? WRITE : READ;
133#ifndef DBUG_OFF159#ifndef DBUG_OFF
134 if (THDVAR(thd, exec_time_debug)) {160 if (THDVAR(thd, exec_time_debug)) {
135 ulonglong t = THDVAR(thd, exec_time_debug);161 ulonglong t = THDVAR(thd, exec_time_debug);
@@ -139,11 +165,13 @@
139 SQLCOM_SET_OPTION )) {165 SQLCOM_SET_OPTION )) {
140 t = 0;166 t = 0;
141 }167 }
142 query_response_time_collect(t);168 query_response_time_collect(query_type, t);
143 }169 }
144 else170 else
145#endif171#endif
146 query_response_time_collect(thd->utime_after_query - thd->utime_after_lock);172 query_response_time_collect(query_type,
173 thd->utime_after_query -
174 thd->utime_after_lock);
147 }175 }
148}176}
149177
@@ -172,6 +200,36 @@
172 0,200 0,
173},201},
174{202{
203 MYSQL_INFORMATION_SCHEMA_PLUGIN,
204 &query_response_time_info_descriptor,
205 "QUERY_RESPONSE_TIME_READ",
206 "Percona and Sergey Vojtovich",
207 "Query Response Time Distribution INFORMATION_SCHEMA Plugin",
208 PLUGIN_LICENSE_GPL,
209 query_response_time_info_init,
210 query_response_time_info_deinit,
211 0x0100,
212 NULL,
213 NULL,
214 (void *)"1.0",
215 0,
216},
217{
218 MYSQL_INFORMATION_SCHEMA_PLUGIN,
219 &query_response_time_info_descriptor,
220 "QUERY_RESPONSE_TIME_WRITE",
221 "Percona and Sergey Vojtovich",
222 "Query Response Time Distribution INFORMATION_SCHEMA Plugin",
223 PLUGIN_LICENSE_GPL,
224 query_response_time_info_init,
225 query_response_time_info_deinit,
226 0x0100,
227 NULL,
228 NULL,
229 (void *)"1.0",
230 0,
231},
232{
175 MYSQL_AUDIT_PLUGIN,233 MYSQL_AUDIT_PLUGIN,
176 &query_response_time_audit_descriptor,234 &query_response_time_audit_descriptor,
177 "QUERY_RESPONSE_TIME_AUDIT",235 "QUERY_RESPONSE_TIME_AUDIT",
178236
=== modified file 'plugin/query_response_time/query_response_time.cc'
--- plugin/query_response_time/query_response_time.cc 2014-09-25 06:33:00 +0000
+++ plugin/query_response_time/query_response_time.cc 2015-02-04 16:22:40 +0000
@@ -170,17 +170,17 @@
170 {170 {
171 my_atomic_rwlock_destroy(&time_collector_lock);171 my_atomic_rwlock_destroy(&time_collector_lock);
172 }172 }
173 uint32 count(uint index)173 uint32 count(QUERY_TYPE type, uint index)
174 {174 {
175 my_atomic_rwlock_rdlock(&time_collector_lock);175 my_atomic_rwlock_rdlock(&time_collector_lock);
176 uint32 result= my_atomic_load32((int32*)&m_count[index]);176 uint32 result= my_atomic_load32((int32*)&m_count[type][index]);
177 my_atomic_rwlock_rdunlock(&time_collector_lock);177 my_atomic_rwlock_rdunlock(&time_collector_lock);
178 return result;178 return result;
179 }179 }
180 uint64 total(uint index)180 uint64 total(QUERY_TYPE type, uint index)
181 {181 {
182 my_atomic_rwlock_rdlock(&time_collector_lock);182 my_atomic_rwlock_rdlock(&time_collector_lock);
183 uint64 result= my_atomic_load64((int64*)&m_total[index]);183 uint64 result= my_atomic_load64((int64*)&m_total[type][index]);
184 my_atomic_rwlock_rdunlock(&time_collector_lock);184 my_atomic_rwlock_rdunlock(&time_collector_lock);
185 return result;185 return result;
186 }186 }
@@ -192,7 +192,7 @@
192 memset((void*)&m_total,0,sizeof(m_total));192 memset((void*)&m_total,0,sizeof(m_total));
193 my_atomic_rwlock_wrunlock(&time_collector_lock);193 my_atomic_rwlock_wrunlock(&time_collector_lock);
194 }194 }
195 void collect(uint64 time)195 void collect(QUERY_TYPE type, uint64 time)
196 {196 {
197 int i= 0;197 int i= 0;
198 for(int count= m_utility->bound_count(); count > i; ++i)198 for(int count= m_utility->bound_count(); count > i; ++i)
@@ -200,8 +200,10 @@
200 if(m_utility->bound(i) > time)200 if(m_utility->bound(i) > time)
201 {201 {
202 my_atomic_rwlock_wrlock(&time_collector_lock);202 my_atomic_rwlock_wrlock(&time_collector_lock);
203 my_atomic_add32((int32*)(&m_count[i]), 1);203 my_atomic_add32((int32*)(&m_count[0][i]), 1);
204 my_atomic_add64((int64*)(&m_total[i]), time);204 my_atomic_add64((int64*)(&m_total[0][i]), time);
205 my_atomic_add32((int32*)(&m_count[type][i]), 1);
206 my_atomic_add64((int64*)(&m_total[type][i]), time);
205 my_atomic_rwlock_wrunlock(&time_collector_lock);207 my_atomic_rwlock_wrunlock(&time_collector_lock);
206 break;208 break;
207 }209 }
@@ -209,12 +211,18 @@
209 }211 }
210private:212private:
211 utility* m_utility;213 utility* m_utility;
212 /* The lock for atomic operations on m_count and m_total. Only actually214 /* The lock for atomic operations on
213 used on architectures that do not have atomic implementation of atomic215 m_count, m_total, m_r_count, m_r_total, m_w_count, m_w_total.
214 operations. */216 Only actually used on architectures that do not have atomic
217 implementation of atomic operations. */
215 my_atomic_rwlock_t time_collector_lock;218 my_atomic_rwlock_t time_collector_lock;
216 uint32 m_count[OVERALL_POWER_COUNT + 1];219 /*
217 uint64 m_total[OVERALL_POWER_COUNT + 1];220 The first row is for overall statistics,
221 the second row is for 'read' queries,
222 the third row is for 'write' queries.
223 */
224 uint32 m_count[3][OVERALL_POWER_COUNT + 1];
225 uint64 m_total[3][OVERALL_POWER_COUNT + 1];
218};226};
219227
220class collector228class collector
@@ -231,7 +239,9 @@
231 m_utility.setup(opt_query_response_time_range_base);239 m_utility.setup(opt_query_response_time_range_base);
232 m_time.flush();240 m_time.flush();
233 }241 }
234 int fill(THD* thd, TABLE_LIST *tables, COND *cond)242 int fill(QUERY_TYPE type,
243 THD* thd,
244 TABLE_LIST *tables, COND *cond)
235 {245 {
236 DBUG_ENTER("fill_schema_query_response_time");246 DBUG_ENTER("fill_schema_query_response_time");
237 TABLE *table= static_cast<TABLE*>(tables->table);247 TABLE *table= static_cast<TABLE*>(tables->table);
@@ -250,10 +260,10 @@
250 else260 else
251 {261 {
252 print_time(time, sizeof(time), TIME_STRING_FORMAT, this->bound(i));262 print_time(time, sizeof(time), TIME_STRING_FORMAT, this->bound(i));
253 print_time(total, sizeof(total), TOTAL_STRING_FORMAT, this->total(i));263 print_time(total, sizeof(total), TOTAL_STRING_FORMAT, this->total(type, i));
254 }264 }
255 fields[0]->store(time,strlen(time),system_charset_info);265 fields[0]->store(time,strlen(time),system_charset_info);
256 fields[1]->store(this->count(i));266 fields[1]->store(this->count(type, i));
257 fields[2]->store(total,strlen(total),system_charset_info);267 fields[2]->store(total,strlen(total),system_charset_info);
258 if (schema_table_store_record(thd, table))268 if (schema_table_store_record(thd, table))
259 {269 {
@@ -262,9 +272,9 @@
262 }272 }
263 DBUG_RETURN(0);273 DBUG_RETURN(0);
264 }274 }
265 void collect(ulonglong time)275 void collect(QUERY_TYPE type, ulonglong time)
266 {276 {
267 m_time.collect(time);277 m_time.collect(type, time);
268 }278 }
269 uint bound_count() const279 uint bound_count() const
270 {280 {
@@ -274,13 +284,13 @@
274 {284 {
275 return m_utility.bound(index);285 return m_utility.bound(index);
276 }286 }
277 ulonglong count(uint index)287 ulonglong count(QUERY_TYPE type, uint index)
278 {288 {
279 return m_time.count(index);289 return m_time.count(type, index);
280 }290 }
281 ulonglong total(uint index)291 ulonglong total(QUERY_TYPE type, uint index)
282 {292 {
283 return m_time.total(index);293 return m_time.total(type, index);
284 }294 }
285private:295private:
286 utility m_utility;296 utility m_utility;
@@ -304,12 +314,23 @@
304{314{
305 query_response_time::g_collector.flush();315 query_response_time::g_collector.flush();
306}316}
307void query_response_time_collect(ulonglong query_time)317
318void query_response_time_collect(QUERY_TYPE type,
319 ulonglong query_time)
308{320{
309 query_response_time::g_collector.collect(query_time);321 query_response_time::g_collector.collect(type, query_time);
310}322}
311323
312int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)324int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
313{325{
314 return query_response_time::g_collector.fill(thd,tables,cond);326 QUERY_TYPE query_type= ANY;
327 if (!strncmp(tables->table->alias,
328 "QUERY_RESPONSE_TIME_READ",
329 sizeof("QUERY_RESPONSE_TIME_READ") - 1))
330 query_type= READ;
331 else if (!strncmp(tables->table->alias,
332 "QUERY_RESPONSE_TIME_WRITE",
333 sizeof("QUERY_RESPONSE_TIME_WRITE") - 1))
334 query_type= WRITE;
335 return query_response_time::g_collector.fill(query_type, thd, tables, cond);
315}336}
316337
=== modified file 'plugin/query_response_time/query_response_time.h'
--- plugin/query_response_time/query_response_time.h 2014-09-25 06:33:00 +0000
+++ plugin/query_response_time/query_response_time.h 2015-02-04 16:22:40 +0000
@@ -66,6 +66,13 @@
66 MY_MAX( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \66 MY_MAX( (QRT_TOTAL_STRING_POSITIVE_POWER_LENGTH + 1 /* '.' */ + 6 /*QRT_TOTAL_STRING_NEGATIVE_POWER_LENGTH*/), \
67 (sizeof(QRT_TIME_OVERFLOW) - 1) )67 (sizeof(QRT_TIME_OVERFLOW) - 1) )
6868
69enum QUERY_TYPE
70{
71 ANY= 0,
72 READ= 1,
73 WRITE= 2
74};
75
69extern ST_SCHEMA_TABLE query_response_time_table;76extern ST_SCHEMA_TABLE query_response_time_table;
7077
71typedef class Item COND;78typedef class Item COND;
@@ -73,7 +80,7 @@
73extern void query_response_time_init ();80extern void query_response_time_init ();
74extern void query_response_time_free ();81extern void query_response_time_free ();
75extern void query_response_time_flush ();82extern void query_response_time_flush ();
76extern void query_response_time_collect(ulonglong query_time);83extern void query_response_time_collect(QUERY_TYPE type, ulonglong query_time);
77extern int query_response_time_fill (THD* thd, TABLE_LIST *tables, COND *cond);84extern int query_response_time_fill (THD* thd, TABLE_LIST *tables, COND *cond);
7885
79extern ulong opt_query_response_time_range_base;86extern ulong opt_query_response_time_range_base;
8087
=== modified file 'plugin/query_response_time/tests/mtr/basic.result'
--- plugin/query_response_time/tests/mtr/basic.result 2014-09-25 06:33:00 +0000
+++ plugin/query_response_time/tests/mtr/basic.result 2015-02-04 16:22:40 +0000
@@ -23,6 +23,18 @@
23PLUGIN_AUTHOR Percona and Sergey Vojtovich23PLUGIN_AUTHOR Percona and Sergey Vojtovich
24PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin24PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
25PLUGIN_LICENSE GPL25PLUGIN_LICENSE GPL
26PLUGIN_NAME QUERY_RESPONSE_TIME_READ
27PLUGIN_VERSION 1.0
28PLUGIN_TYPE INFORMATION SCHEMA
29PLUGIN_AUTHOR Percona and Sergey Vojtovich
30PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
31PLUGIN_LICENSE GPL
32PLUGIN_NAME QUERY_RESPONSE_TIME_WRITE
33PLUGIN_VERSION 1.0
34PLUGIN_TYPE INFORMATION SCHEMA
35PLUGIN_AUTHOR Percona and Sergey Vojtovich
36PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
37PLUGIN_LICENSE GPL
26SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;38SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
27SELECT 1;39SELECT 1;
281401
2941
=== added file 'plugin/query_response_time/tests/mtr/query_response_time-rw-begin.inc'
--- plugin/query_response_time/tests/mtr/query_response_time-rw-begin.inc 1970-01-01 00:00:00 +0000
+++ plugin/query_response_time/tests/mtr/query_response_time-rw-begin.inc 2015-02-04 16:22:40 +0000
@@ -0,0 +1,16 @@
1--disable_query_log
2--disable_result_log
3SET GLOBAL QUERY_RESPONSE_TIME_STATS = 0;
4SET GLOBAL QUERY_RESPONSE_TIME_FLUSH = 1;
5SET SESSION QUERY_RESPONSE_TIME_EXEC_TIME_DEBUG = 500000;
6--enable_query_log
7--enable_result_log
8SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
9SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
10SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
11--disable_query_log
12--disable_result_log
13SET GLOBAL QUERY_RESPONSE_TIME_STATS = 1;
14--enable_query_log
15--enable_result_log
16--echo ------------------Test body begin--------------------
017
=== added file 'plugin/query_response_time/tests/mtr/query_response_time-rw-end.inc'
--- plugin/query_response_time/tests/mtr/query_response_time-rw-end.inc 1970-01-01 00:00:00 +0000
+++ plugin/query_response_time/tests/mtr/query_response_time-rw-end.inc 2015-02-04 16:22:40 +0000
@@ -0,0 +1,10 @@
1--echo ------------------Test body end----------------------
2--disable_query_log
3--disable_result_log
4SET GLOBAL QUERY_RESPONSE_TIME_STATS = 0;
5SET SESSION QUERY_RESPONSE_TIME_EXEC_TIME_DEBUG = DEFAULT;
6--enable_query_log
7--enable_result_log
8SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
9SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
10SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
011
=== added file 'plugin/query_response_time/tests/mtr/query_response_time-rw.result'
--- plugin/query_response_time/tests/mtr/query_response_time-rw.result 1970-01-01 00:00:00 +0000
+++ plugin/query_response_time/tests/mtr/query_response_time-rw.result 2015-02-04 16:22:40 +0000
@@ -0,0 +1,765 @@
1CREATE FUNCTION DML_FUNC()
2RETURNS INT
3BEGIN
4INSERT INTO t1 (b) VALUES (1), (2);
5UPDATE t1 SET b = 1;
6RETURN 1;
7END|
8CREATE PROCEDURE NESTED_PROC()
9BEGIN
10SELECT DML_FUNC();
11END|
12SET default_storage_engine=InnoDB;
13
14============================
15= Test for simple DML and DDL
16============================
17
18SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
19TIME COUNT TOTAL
20SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
21TIME COUNT TOTAL
22SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
23TIME COUNT TOTAL
24------------------Test body begin--------------------
25CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
26b INT UNSIGNED NOT NULL DEFAULT 0);
27INSERT INTO t1 (b) VALUES (1), (2);
28UPDATE t1 SET b = 1;
29SELECT * FROM t1;
30a b
311 1
322 1
33DELETE FROM t1;
34ALTER TABLE t1 ADD COLUMN (c INT);
35DROP TABLE t1;
36------------------Test body end----------------------
37SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
38TIME COUNT TOTAL
39 0.000001 1 0.000000
40 1.000000 7 3.500000
41SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
42TIME COUNT TOTAL
43 0.000001 1 0.000000
44 1.000000 1 0.500000
45SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
46TIME COUNT TOTAL
47 1.000000 6 3.000000
48CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
49b INT(10) UNSIGNED NOT NULL DEFAULT 0);
50
51============================
52= Test for SELECT+DML
53============================
54
55SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
56TIME COUNT TOTAL
57SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
58TIME COUNT TOTAL
59SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
60TIME COUNT TOTAL
61------------------Test body begin--------------------
62SELECT DML_FUNC();
63DML_FUNC()
641
65------------------Test body end----------------------
66SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
67TIME COUNT TOTAL
68 0.000001 1 0.000000
69 1.000000 3 1.500000
70SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
71TIME COUNT TOTAL
72 0.000001 1 0.000000
73 1.000000 1 0.500000
74SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
75TIME COUNT TOTAL
76 1.000000 2 1.000000
77
78============================
79= Test for nested calls
80============================
81
82SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
83TIME COUNT TOTAL
84SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
85TIME COUNT TOTAL
86SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
87TIME COUNT TOTAL
88------------------Test body begin--------------------
89CALL NESTED_PROC();
90DML_FUNC()
911
92------------------Test body end----------------------
93SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
94TIME COUNT TOTAL
95 0.000001 1 0.000000
96 1.000000 4 2.000000
97SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
98TIME COUNT TOTAL
99 0.000001 1 0.000000
100 1.000000 2 1.000000
101SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
102TIME COUNT TOTAL
103 1.000000 2 1.000000
104
105============================
106= Test for 'PREPARE'
107============================
108
109SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
110TIME COUNT TOTAL
111SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
112TIME COUNT TOTAL
113SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
114TIME COUNT TOTAL
115------------------Test body begin--------------------
116PREPARE rw_stmt FROM 'DELETE FROM t1';
117PREPARE ro_stmt FROM 'SELECT * FROM t1';
118PREPARE select_dml_stmt FROM 'SELECT DML_FUNC()';
119PREPARE nested_call_stmt FROM 'CALL NESTED_PROC()';
120------------------Test body end----------------------
121SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
122TIME COUNT TOTAL
123 0.000001 1 0.000000
124 1.000000 4 2.000000
125SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
126TIME COUNT TOTAL
127 0.000001 1 0.000000
128 1.000000 4 2.000000
129SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
130TIME COUNT TOTAL
131
132============================
133= Test for 'EXECUTE'
134============================
135
136SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
137TIME COUNT TOTAL
138SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
139TIME COUNT TOTAL
140SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
141TIME COUNT TOTAL
142------------------Test body begin--------------------
143EXECUTE rw_stmt;
144EXECUTE ro_stmt;
145a b
146EXECUTE select_dml_stmt;
147DML_FUNC()
1481
149EXECUTE nested_call_stmt;
150DML_FUNC()
1511
152------------------Test body end----------------------
153SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
154TIME COUNT TOTAL
155 0.000001 1 0.000000
156 1.000000 9 4.500000
157SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
158TIME COUNT TOTAL
159 0.000001 1 0.000000
160 1.000000 4 2.000000
161SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
162TIME COUNT TOTAL
163 1.000000 5 2.500000
164
165============================
166= Test for 'DEALLOCATE PREPARE'
167============================
168
169SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
170TIME COUNT TOTAL
171SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
172TIME COUNT TOTAL
173SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
174TIME COUNT TOTAL
175------------------Test body begin--------------------
176DEALLOCATE PREPARE rw_stmt;
177DEALLOCATE PREPARE ro_stmt;
178DEALLOCATE PREPARE select_dml_stmt;
179DEALLOCATE PREPARE nested_call_stmt;
180------------------Test body end----------------------
181SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
182TIME COUNT TOTAL
183 0.000001 1 0.000000
184 1.000000 4 2.000000
185SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
186TIME COUNT TOTAL
187 0.000001 1 0.000000
188 1.000000 4 2.000000
189SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
190TIME COUNT TOTAL
191
192============================
193= Test for transactions
194============================
195
196SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
197TIME COUNT TOTAL
198SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
199TIME COUNT TOTAL
200SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
201TIME COUNT TOTAL
202------------------Test body begin--------------------
203BEGIN;
204SELECT * FROM t1;
205a b
2065 1
2076 1
2087 1
2098 1
210COMMIT;
211------------------Test body end----------------------
212SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
213TIME COUNT TOTAL
214 0.000001 1 0.000000
215 1.000000 3 1.500000
216SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
217TIME COUNT TOTAL
218 0.000001 1 0.000000
219 1.000000 3 1.500000
220SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
221TIME COUNT TOTAL
222SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
223TIME COUNT TOTAL
224SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
225TIME COUNT TOTAL
226SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
227TIME COUNT TOTAL
228------------------Test body begin--------------------
229BEGIN;
230INSERT INTO t1 (b) VALUES (1), (2);
231UPDATE t1 SET b = 1;
232SELECT * FROM t1;
233a b
2345 1
2356 1
2367 1
2378 1
2389 1
23910 1
240DELETE FROM t1;
241COMMIT;
242------------------Test body end----------------------
243SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
244TIME COUNT TOTAL
245 0.000001 1 0.000000
246 1.000000 6 3.000000
247SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
248TIME COUNT TOTAL
249 0.000001 1 0.000000
250 1.000000 3 1.500000
251SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
252TIME COUNT TOTAL
253 1.000000 3 1.500000
254SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
255TIME COUNT TOTAL
256SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
257TIME COUNT TOTAL
258SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
259TIME COUNT TOTAL
260------------------Test body begin--------------------
261BEGIN;
262SELECT DML_FUNC();
263DML_FUNC()
2641
265CALL NESTED_PROC();
266DML_FUNC()
2671
268COMMIT;
269------------------Test body end----------------------
270SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
271TIME COUNT TOTAL
272 0.000001 1 0.000000
273 1.000000 9 4.500000
274SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
275TIME COUNT TOTAL
276 0.000001 1 0.000000
277 1.000000 5 2.500000
278SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
279TIME COUNT TOTAL
280 1.000000 4 2.000000
281SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
282TIME COUNT TOTAL
283SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
284TIME COUNT TOTAL
285SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
286TIME COUNT TOTAL
287------------------Test body begin--------------------
288BEGIN;
289INSERT INTO t1 (b) VALUES (1), (2);
290UPDATE t1 SET b = 1;
291ROLLBACK;
292------------------Test body end----------------------
293SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
294TIME COUNT TOTAL
295 0.000001 1 0.000000
296 1.000000 4 2.000000
297SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
298TIME COUNT TOTAL
299 0.000001 1 0.000000
300 1.000000 2 1.000000
301SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
302TIME COUNT TOTAL
303 1.000000 2 1.000000
304
305============================
306= Test for implicit commit
307============================
308
309SET autocommit = 0;
310SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
311TIME COUNT TOTAL
312SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
313TIME COUNT TOTAL
314SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
315TIME COUNT TOTAL
316------------------Test body begin--------------------
317INSERT INTO t1 (b) VALUES (1), (2);
318CREATE INDEX ab ON t1 (a, b);
319------------------Test body end----------------------
320SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
321TIME COUNT TOTAL
322 0.000001 1 0.000000
323 1.000000 2 1.000000
324SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
325TIME COUNT TOTAL
326 0.000001 1 0.000000
327SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
328TIME COUNT TOTAL
329 1.000000 2 1.000000
330SET autocommit = 1;
331
332============================
333= Test for trigger
334============================
335
336CREATE TABLE t2 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
337b INT UNSIGNED NOT NULL DEFAULT 0);
338SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
339TIME COUNT TOTAL
340SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
341TIME COUNT TOTAL
342SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
343TIME COUNT TOTAL
344------------------Test body begin--------------------
345CREATE TRIGGER test_trigger BEFORE INSERT ON t1
346FOR EACH ROW
347BEGIN
348INSERT INTO t2 SET b = NEW.b;
349INSERT INTO t2 SET b = NEW.b;
350END;
351|
352------------------Test body end----------------------
353SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
354TIME COUNT TOTAL
355 0.000001 1 0.000000
356 1.000000 1 0.500000
357SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
358TIME COUNT TOTAL
359 0.000001 1 0.000000
360SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
361TIME COUNT TOTAL
362 1.000000 1 0.500000
363SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
364TIME COUNT TOTAL
365SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
366TIME COUNT TOTAL
367SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
368TIME COUNT TOTAL
369------------------Test body begin--------------------
370INSERT INTO t1 (b) VALUES (1), (2);
371------------------Test body end----------------------
372SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
373TIME COUNT TOTAL
374 0.000001 1 0.000000
375 1.000000 5 2.500000
376SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
377TIME COUNT TOTAL
378 0.000001 1 0.000000
379SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
380TIME COUNT TOTAL
381 1.000000 5 2.500000
382DROP TABLE t1;
383DROP TABLE t2;
384SET default_storage_engine=InnoDB;
385SET default_storage_engine=MyISAM;
386
387==========================
388= Test for Innodb engine
389==========================
390
391============================
392= Test for simple DML and DDL
393============================
394
395SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
396TIME COUNT TOTAL
397SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
398TIME COUNT TOTAL
399SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
400TIME COUNT TOTAL
401------------------Test body begin--------------------
402CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
403b INT UNSIGNED NOT NULL DEFAULT 0);
404INSERT INTO t1 (b) VALUES (1), (2);
405UPDATE t1 SET b = 1;
406SELECT * FROM t1;
407a b
4081 1
4092 1
410DELETE FROM t1;
411ALTER TABLE t1 ADD COLUMN (c INT);
412DROP TABLE t1;
413------------------Test body end----------------------
414SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
415TIME COUNT TOTAL
416 0.000001 1 0.000000
417 1.000000 7 3.500000
418SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
419TIME COUNT TOTAL
420 0.000001 1 0.000000
421 1.000000 1 0.500000
422SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
423TIME COUNT TOTAL
424 1.000000 6 3.000000
425CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
426b INT(10) UNSIGNED NOT NULL DEFAULT 0);
427
428============================
429= Test for SELECT+DML
430============================
431
432SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
433TIME COUNT TOTAL
434SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
435TIME COUNT TOTAL
436SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
437TIME COUNT TOTAL
438------------------Test body begin--------------------
439SELECT DML_FUNC();
440DML_FUNC()
4411
442------------------Test body end----------------------
443SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
444TIME COUNT TOTAL
445 0.000001 1 0.000000
446 1.000000 3 1.500000
447SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
448TIME COUNT TOTAL
449 0.000001 1 0.000000
450 1.000000 1 0.500000
451SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
452TIME COUNT TOTAL
453 1.000000 2 1.000000
454
455============================
456= Test for nested calls
457============================
458
459SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
460TIME COUNT TOTAL
461SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
462TIME COUNT TOTAL
463SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
464TIME COUNT TOTAL
465------------------Test body begin--------------------
466CALL NESTED_PROC();
467DML_FUNC()
4681
469------------------Test body end----------------------
470SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
471TIME COUNT TOTAL
472 0.000001 1 0.000000
473 1.000000 4 2.000000
474SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
475TIME COUNT TOTAL
476 0.000001 1 0.000000
477 1.000000 2 1.000000
478SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
479TIME COUNT TOTAL
480 1.000000 2 1.000000
481
482============================
483= Test for 'PREPARE'
484============================
485
486SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
487TIME COUNT TOTAL
488SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
489TIME COUNT TOTAL
490SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
491TIME COUNT TOTAL
492------------------Test body begin--------------------
493PREPARE rw_stmt FROM 'DELETE FROM t1';
494PREPARE ro_stmt FROM 'SELECT * FROM t1';
495PREPARE select_dml_stmt FROM 'SELECT DML_FUNC()';
496PREPARE nested_call_stmt FROM 'CALL NESTED_PROC()';
497------------------Test body end----------------------
498SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
499TIME COUNT TOTAL
500 0.000001 1 0.000000
501 1.000000 4 2.000000
502SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
503TIME COUNT TOTAL
504 0.000001 1 0.000000
505 1.000000 4 2.000000
506SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
507TIME COUNT TOTAL
508
509============================
510= Test for 'EXECUTE'
511============================
512
513SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
514TIME COUNT TOTAL
515SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
516TIME COUNT TOTAL
517SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
518TIME COUNT TOTAL
519------------------Test body begin--------------------
520EXECUTE rw_stmt;
521EXECUTE ro_stmt;
522a b
523EXECUTE select_dml_stmt;
524DML_FUNC()
5251
526EXECUTE nested_call_stmt;
527DML_FUNC()
5281
529------------------Test body end----------------------
530SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
531TIME COUNT TOTAL
532 0.000001 1 0.000000
533 1.000000 9 4.500000
534SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
535TIME COUNT TOTAL
536 0.000001 1 0.000000
537 1.000000 4 2.000000
538SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
539TIME COUNT TOTAL
540 1.000000 5 2.500000
541
542============================
543= Test for 'DEALLOCATE PREPARE'
544============================
545
546SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
547TIME COUNT TOTAL
548SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
549TIME COUNT TOTAL
550SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
551TIME COUNT TOTAL
552------------------Test body begin--------------------
553DEALLOCATE PREPARE rw_stmt;
554DEALLOCATE PREPARE ro_stmt;
555DEALLOCATE PREPARE select_dml_stmt;
556DEALLOCATE PREPARE nested_call_stmt;
557------------------Test body end----------------------
558SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
559TIME COUNT TOTAL
560 0.000001 1 0.000000
561 1.000000 4 2.000000
562SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
563TIME COUNT TOTAL
564 0.000001 1 0.000000
565 1.000000 4 2.000000
566SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
567TIME COUNT TOTAL
568
569============================
570= Test for transactions
571============================
572
573SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
574TIME COUNT TOTAL
575SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
576TIME COUNT TOTAL
577SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
578TIME COUNT TOTAL
579------------------Test body begin--------------------
580BEGIN;
581SELECT * FROM t1;
582a b
5835 1
5846 1
5857 1
5868 1
587COMMIT;
588------------------Test body end----------------------
589SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
590TIME COUNT TOTAL
591 0.000001 1 0.000000
592 1.000000 3 1.500000
593SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
594TIME COUNT TOTAL
595 0.000001 1 0.000000
596 1.000000 3 1.500000
597SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
598TIME COUNT TOTAL
599SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
600TIME COUNT TOTAL
601SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
602TIME COUNT TOTAL
603SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
604TIME COUNT TOTAL
605------------------Test body begin--------------------
606BEGIN;
607INSERT INTO t1 (b) VALUES (1), (2);
608UPDATE t1 SET b = 1;
609SELECT * FROM t1;
610a b
6115 1
6126 1
6137 1
6148 1
6159 1
61610 1
617DELETE FROM t1;
618COMMIT;
619------------------Test body end----------------------
620SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
621TIME COUNT TOTAL
622 0.000001 1 0.000000
623 1.000000 6 3.000000
624SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
625TIME COUNT TOTAL
626 0.000001 1 0.000000
627 1.000000 3 1.500000
628SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
629TIME COUNT TOTAL
630 1.000000 3 1.500000
631SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
632TIME COUNT TOTAL
633SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
634TIME COUNT TOTAL
635SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
636TIME COUNT TOTAL
637------------------Test body begin--------------------
638BEGIN;
639SELECT DML_FUNC();
640DML_FUNC()
6411
642CALL NESTED_PROC();
643DML_FUNC()
6441
645COMMIT;
646------------------Test body end----------------------
647SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
648TIME COUNT TOTAL
649 0.000001 1 0.000000
650 1.000000 9 4.500000
651SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
652TIME COUNT TOTAL
653 0.000001 1 0.000000
654 1.000000 5 2.500000
655SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
656TIME COUNT TOTAL
657 1.000000 4 2.000000
658SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
659TIME COUNT TOTAL
660SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
661TIME COUNT TOTAL
662SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
663TIME COUNT TOTAL
664------------------Test body begin--------------------
665BEGIN;
666INSERT INTO t1 (b) VALUES (1), (2);
667UPDATE t1 SET b = 1;
668ROLLBACK;
669Warnings:
670Warning 1196 Some non-transactional changed tables couldn't be rolled back
671------------------Test body end----------------------
672SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
673TIME COUNT TOTAL
674 0.000001 1 0.000000
675 1.000000 5 2.500000
676SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
677TIME COUNT TOTAL
678 0.000001 1 0.000000
679 1.000000 3 1.500000
680SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
681TIME COUNT TOTAL
682 1.000000 2 1.000000
683
684============================
685= Test for implicit commit
686============================
687
688SET autocommit = 0;
689SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
690TIME COUNT TOTAL
691SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
692TIME COUNT TOTAL
693SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
694TIME COUNT TOTAL
695------------------Test body begin--------------------
696INSERT INTO t1 (b) VALUES (1), (2);
697CREATE INDEX ab ON t1 (a, b);
698------------------Test body end----------------------
699SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
700TIME COUNT TOTAL
701 0.000001 1 0.000000
702 1.000000 2 1.000000
703SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
704TIME COUNT TOTAL
705 0.000001 1 0.000000
706SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
707TIME COUNT TOTAL
708 1.000000 2 1.000000
709SET autocommit = 1;
710
711============================
712= Test for trigger
713============================
714
715CREATE TABLE t2 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
716b INT UNSIGNED NOT NULL DEFAULT 0);
717SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
718TIME COUNT TOTAL
719SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
720TIME COUNT TOTAL
721SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
722TIME COUNT TOTAL
723------------------Test body begin--------------------
724CREATE TRIGGER test_trigger BEFORE INSERT ON t1
725FOR EACH ROW
726BEGIN
727INSERT INTO t2 SET b = NEW.b;
728INSERT INTO t2 SET b = NEW.b;
729END;
730|
731------------------Test body end----------------------
732SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
733TIME COUNT TOTAL
734 0.000001 1 0.000000
735 1.000000 1 0.500000
736SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
737TIME COUNT TOTAL
738 0.000001 1 0.000000
739SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
740TIME COUNT TOTAL
741 1.000000 1 0.500000
742SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
743TIME COUNT TOTAL
744SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
745TIME COUNT TOTAL
746SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
747TIME COUNT TOTAL
748------------------Test body begin--------------------
749INSERT INTO t1 (b) VALUES (1), (2);
750------------------Test body end----------------------
751SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
752TIME COUNT TOTAL
753 0.000001 1 0.000000
754 1.000000 5 2.500000
755SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
756TIME COUNT TOTAL
757 0.000001 1 0.000000
758SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
759TIME COUNT TOTAL
760 1.000000 5 2.500000
761DROP TABLE t1;
762DROP TABLE t2;
763SET default_storage_engine=default;
764DROP FUNCTION DML_FUNC;
765DROP PROCEDURE NESTED_PROC;
0766
=== added file 'plugin/query_response_time/tests/mtr/query_response_time-rw.test'
--- plugin/query_response_time/tests/mtr/query_response_time-rw.test 1970-01-01 00:00:00 +0000
+++ plugin/query_response_time/tests/mtr/query_response_time-rw.test 2015-02-04 16:22:40 +0000
@@ -0,0 +1,201 @@
1--source include/have_query_response_time_plugin.inc
2--source include/have_debug.inc
3
4# The file with expected results fits only to a run without
5# ps-protocol/sp-protocol/cursor-protocol/view-protocol.
6if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
7 + $VIEW_PROTOCOL > 0`)
8{
9 --skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
10}
11
12--delimiter |
13
14CREATE FUNCTION DML_FUNC()
15RETURNS INT
16BEGIN
17 INSERT INTO t1 (b) VALUES (1), (2);
18 UPDATE t1 SET b = 1;
19 RETURN 1;
20END|
21
22CREATE PROCEDURE NESTED_PROC()
23BEGIN
24 SELECT DML_FUNC();
25END|
26
27--delimiter ;
28
29--let $i=2
30
31while ($i)
32{
33
34 SET default_storage_engine=InnoDB;
35 if ($i==1)
36 {
37 SET default_storage_engine=MyISAM;
38 }
39
40 if ($i==0)
41 {
42 --echo
43 --echo ==========================
44 --echo = Test for MyISAM engine
45 --echo ==========================
46 --echo
47 }
48 if ($i==1)
49 {
50 --echo
51 --echo ==========================
52 --echo = Test for Innodb engine
53 --echo ==========================
54 }
55
56 --echo
57 --echo ============================
58 --echo = Test for simple DML and DDL
59 --echo ============================
60 --echo
61 --source query_response_time-rw-begin.inc
62 CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
63 b INT UNSIGNED NOT NULL DEFAULT 0);
64 INSERT INTO t1 (b) VALUES (1), (2);
65 UPDATE t1 SET b = 1;
66 SELECT * FROM t1;
67 DELETE FROM t1;
68 ALTER TABLE t1 ADD COLUMN (c INT);
69 DROP TABLE t1;
70 --source query_response_time-rw-end.inc
71
72 CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
73 b INT(10) UNSIGNED NOT NULL DEFAULT 0);
74 --echo
75 --echo ============================
76 --echo = Test for SELECT+DML
77 --echo ============================
78 --echo
79 --source query_response_time-rw-begin.inc
80 SELECT DML_FUNC();
81 --source query_response_time-rw-end.inc
82
83 --echo
84 --echo ============================
85 --echo = Test for nested calls
86 --echo ============================
87 --echo
88 --source query_response_time-rw-begin.inc
89 CALL NESTED_PROC();
90 --source query_response_time-rw-end.inc
91
92 --echo
93 --echo ============================
94 --echo = Test for 'PREPARE'
95 --echo ============================
96 --echo
97 --source query_response_time-rw-begin.inc
98 PREPARE rw_stmt FROM 'DELETE FROM t1';
99 PREPARE ro_stmt FROM 'SELECT * FROM t1';
100 PREPARE select_dml_stmt FROM 'SELECT DML_FUNC()';
101 PREPARE nested_call_stmt FROM 'CALL NESTED_PROC()';
102 --source query_response_time-rw-end.inc
103
104 --echo
105 --echo ============================
106 --echo = Test for 'EXECUTE'
107 --echo ============================
108 --echo
109 --source query_response_time-rw-begin.inc
110 EXECUTE rw_stmt;
111 EXECUTE ro_stmt;
112 EXECUTE select_dml_stmt;
113 EXECUTE nested_call_stmt;
114 --source query_response_time-rw-end.inc
115
116 --echo
117 --echo ============================
118 --echo = Test for 'DEALLOCATE PREPARE'
119 --echo ============================
120 --echo
121 --source query_response_time-rw-begin.inc
122 DEALLOCATE PREPARE rw_stmt;
123 DEALLOCATE PREPARE ro_stmt;
124 DEALLOCATE PREPARE select_dml_stmt;
125 DEALLOCATE PREPARE nested_call_stmt;
126 --source query_response_time-rw-end.inc
127
128 --echo
129 --echo ============================
130 --echo = Test for transactions
131 --echo ============================
132 --echo
133 --source query_response_time-rw-begin.inc
134 BEGIN;
135 SELECT * FROM t1;
136 COMMIT;
137 --source query_response_time-rw-end.inc
138 --source query_response_time-rw-begin.inc
139 BEGIN;
140 INSERT INTO t1 (b) VALUES (1), (2);
141 UPDATE t1 SET b = 1;
142 SELECT * FROM t1;
143 DELETE FROM t1;
144 COMMIT;
145 --source query_response_time-rw-end.inc
146 --source query_response_time-rw-begin.inc
147 BEGIN;
148 SELECT DML_FUNC();
149 CALL NESTED_PROC();
150 COMMIT;
151 --source query_response_time-rw-end.inc
152 --source query_response_time-rw-begin.inc
153 BEGIN;
154 INSERT INTO t1 (b) VALUES (1), (2);
155 UPDATE t1 SET b = 1;
156 ROLLBACK;
157 --source query_response_time-rw-end.inc
158
159 --echo
160 --echo ============================
161 --echo = Test for implicit commit
162 --echo ============================
163 --echo
164 SET autocommit = 0;
165 --source query_response_time-rw-begin.inc
166 INSERT INTO t1 (b) VALUES (1), (2);
167 CREATE INDEX ab ON t1 (a, b);
168 --source query_response_time-rw-end.inc
169 SET autocommit = 1;
170
171 --echo
172 --echo ============================
173 --echo = Test for trigger
174 --echo ============================
175 --echo
176 CREATE TABLE t2 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
177 b INT UNSIGNED NOT NULL DEFAULT 0);
178 --source query_response_time-rw-begin.inc
179 --delimiter |
180 CREATE TRIGGER test_trigger BEFORE INSERT ON t1
181 FOR EACH ROW
182 BEGIN
183 INSERT INTO t2 SET b = NEW.b;
184 INSERT INTO t2 SET b = NEW.b;
185 END;
186 |
187 --delimiter ;
188 --source query_response_time-rw-end.inc
189 --source query_response_time-rw-begin.inc
190 INSERT INTO t1 (b) VALUES (1), (2);
191 --source query_response_time-rw-end.inc
192
193 DROP TABLE t1;
194 DROP TABLE t2;
195
196 --dec $i
197}
198
199SET default_storage_engine=default;
200DROP FUNCTION DML_FUNC;
201DROP PROCEDURE NESTED_PROC;
0202
=== modified file 'sql/sp_instr.cc'
--- sql/sp_instr.cc 2014-09-25 07:10:58 +0000
+++ sql/sp_instr.cc 2015-02-04 16:22:40 +0000
@@ -821,11 +821,21 @@
821 {821 {
822 rc= validate_lex_and_execute_core(thd, nextp, false);822 rc= validate_lex_and_execute_core(thd, nextp, false);
823823
824 /*
825 thd->utime_after_query can be used for counting
826 statement execution time (for example in
827 query_response_time plugin). thd->update_server_status()
828 updates this value but only if function/procedure
829 budy has been already executed, if we want to measure
830 statement execution time inside function/procedure
831 we have to update this value here independent of
832 value returned by thd->get_stmt_da()->is_eof().
833 */
834 thd->update_server_status();
835
824 if (thd->get_stmt_da()->is_eof())836 if (thd->get_stmt_da()->is_eof())
825 {837 {
826 /* Finalize server status flags after executing a statement. */838 /* Finalize server status flags after executing a statement. */
827 thd->update_server_status();
828
829 thd->protocol->end_statement();839 thd->protocol->end_statement();
830 }840 }
831841

Subscribers

People subscribed via source and target branches