mirror/mariadb
1
0
Fork 0
mirror of https://github.com/MariaDB/server.git synced 2025-03-26 17:08:41 +01:00
Code Issues Projects Releases Packages Wiki Activity Actions1

MDEV-33501 Extend query_response_time plugin to be compatible with Percona server

Browse source 
This is to update the plugin to be compatible with Percona's
query_response_time plugin, with some additions.
Some of the tests are taken from Percona server.

- Added plugins QUERY_RESPONSE_TIME_READ, QUERY_RESPONSE_TIME_WRITE and
  QUERY_RESPONSE_TIME_READ_WRITE.
- Added option query_response_time_session_stats, with possible values
  GLOBAL, ON or OFF, to the query_response_time plugin.

Notes:
- All modules are dependent on QUERY_RESPONSE_READ_TIME. This must always
  be enabled if any of the other modules are used.
  This will be auto-enabled in the near future.
- Accounting are done per statement. Stored functions are regarded
  as part of the original statement.
- For stored procedures the accounting are done per statement executed
  in the stored procedure. CALL will not be accounted because of this.
- FLUSH commands will not be accounted for. This is to ensure that
  FLUSH QUERY_RESPONSE_TIME is not part of the statistics.
  (This helps when testing with mtr and otherwise).
- FLUSH QUERY_RESPONSE_TIME_READ and FLUSH QUERY_RESPONSE_TIME_READ
  only resets the corresponding status.
- FLUSH QUERY_RESPONSE_TIME and FLUSH QUERY_RESPONSE_TIME_READ_WRITE or
  changing the value of query_response_time_range_base followed by
  any FLUSH of QUERY_RESPOSNSE_TIME resets all status.
This commit is contained in:
Monty 2024-02-20 17:25:40 +02:00 • committed by Sergei Golubchik
parent 5296f908ed
commit 243b9f3cd2
27 changed files with 2094 additions and 450 deletions

22
plugin/query_response_time/mysql-test/query_response_time/basic.result
View file

@ -2,6 +2,7 @@ SHOW VARIABLES WHERE VARIABLE_NAME LIKE 'query_response_time%' AND VARIABLE_NAME
Variable_name Value
query_response_time_flush OFF
query_response_time_range_base 10
query_response_time_session_stats GLOBAL
query_response_time_stats OFF
SHOW CREATE TABLE INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
Table Create Table
@ -18,6 +19,27 @@ PLUGIN_AUTHOR Percona and Sergey Vojtovich
PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
PLUGIN_LICENSE GPL
PLUGIN_MATURITY Stable
PLUGIN_NAME QUERY_RESPONSE_TIME_READ
PLUGIN_VERSION 1.0
PLUGIN_TYPE INFORMATION SCHEMA
PLUGIN_AUTHOR Percona and Sergey Vojtovich
PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
PLUGIN_LICENSE GPL
PLUGIN_MATURITY Stable
PLUGIN_NAME QUERY_RESPONSE_TIME_WRITE
PLUGIN_VERSION 1.0
PLUGIN_TYPE INFORMATION SCHEMA
PLUGIN_AUTHOR Percona and Sergey Vojtovich
PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
PLUGIN_LICENSE GPL
PLUGIN_MATURITY Stable
PLUGIN_NAME QUERY_RESPONSE_TIME_READ_WRITE
PLUGIN_VERSION 1.0
PLUGIN_TYPE INFORMATION SCHEMA
PLUGIN_AUTHOR Monty
PLUGIN_DESCRIPTION Query Response Time Distribution INFORMATION_SCHEMA Plugin
PLUGIN_LICENSE GPL
PLUGIN_MATURITY Stable
PLUGIN_NAME QUERY_RESPONSE_TIME_AUDIT
PLUGIN_VERSION 1.0
PLUGIN_TYPE AUDIT

32
plugin/query_response_time/mysql-test/query_response_time/query_response_time-check.inc Normal file
View file

@ -0,0 +1,32 @@
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME WHERE count != 0;
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ WHERE count != 0;
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE WHERE count != 0;
--disable_query_log
--let $assert_text= The sum of query counts in read and write tables must be equal to query count of the common table
SELECT SUM(COUNT) INTO @common_count FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SELECT SUM(COUNT) INTO @ro_count FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_READ;
SELECT SUM(COUNT) INTO @rw_count FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME_WRITE;
--let $assert_cond= @common_count = @ro_count + @rw_count;
--source include/assert.inc
#
# Bug 1552428: table contents should not depend on the table case name
#
--let $assert_text= QUERY_RESPONSE_TIME query counts must be equal regardless of the table name case
SELECT SUM(COUNT) INTO @common_count_lc FROM information_schema.query_response_time;
--let $assert_cond= @common_count = @common_count_lc
--source include/assert.inc
--let $assert_text= QUERY_RESPONSE_TIME_READ query counts must be equal regardless of the table name case
SELECT SUM(COUNT) INTO @ro_count_lc FROM information_schema.query_response_time_read;
--let $assert_cond= @ro_count = @ro_count_lc
--source include/assert.inc
--let $assert_text= QUERY_RESPONSE_TIME_WRITE query counts must be equal regardless of the table name case
SELECT SUM(COUNT) INTO @rw_count_lc FROM information_schema.query_response_time_write;
--let $assert_cond= @rw_count = @rw_count_lc
--source include/assert.inc
--enable_query_log

15
plugin/query_response_time/mysql-test/query_response_time/query_response_time-rw-begin.inc Normal file
View file

@ -0,0 +1,15 @@
--disable_query_log
--disable_result_log
SET GLOBAL QUERY_RESPONSE_TIME_STATS = 0;
SET SESSION QUERY_RESPONSE_TIME_EXEC_TIME_DEBUG = 500000;
FLUSH QUERY_RESPONSE_TIME;
--enable_query_log
--enable_result_log
--source query_response_time-check.inc
--disable_query_log
--disable_result_log
SET GLOBAL QUERY_RESPONSE_TIME_STATS = 1;
FLUSH QUERY_RESPONSE_TIME;
--enable_query_log
--enable_result_log
--echo ------------------Test body begin--------------------

6
plugin/query_response_time/mysql-test/query_response_time/query_response_time-rw-end.inc Normal file
View file

@ -0,0 +1,6 @@
--echo ------------------Test body end----------------------
--disable_query_log
SET GLOBAL QUERY_RESPONSE_TIME_STATS = 0;
SET SESSION QUERY_RESPONSE_TIME_EXEC_TIME_DEBUG = DEFAULT;
--enable_query_log
--source query_response_time-check.inc

1012
plugin/query_response_time/mysql-test/query_response_time/query_response_time-rw.result Normal file
View file

File diff suppressed because it is too large Load diff

240
plugin/query_response_time/mysql-test/query_response_time/query_response_time-rw.test Normal file
View file

@ -0,0 +1,240 @@
--source include/have_debug.inc
--source include/have_innodb.inc
# The file with expected results fits only to a run without
# ps-protocol/sp-protocol/cursor-protocol/view-protocol.
if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
+ $VIEW_PROTOCOL > 0`)
{
--skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
}
--delimiter |
CREATE FUNCTION DML_FUNC()
RETURNS INT
BEGIN
INSERT INTO t1 (b) VALUES (1), (2);
UPDATE t1 SET b = 1;
RETURN 1;
END|
CREATE PROCEDURE NESTED_PROC()
BEGIN
SELECT DML_FUNC();
END|
CREATE PROCEDURE PREPARE_EXECUTE_PROC()
BEGIN
PREPARE p_stmt_select FROM "SELECT 1";
PREPARE p_stmt_insert FROM "INSERT INTO t1 (b) VALUES (1), (2)";
PREPARE p_stmt_update FROM "UPDATE t1 SET b = 1";
EXECUTE p_stmt_select;
EXECUTE p_stmt_insert;
EXECUTE p_stmt_update;
DEALLOCATE PREPARE p_stmt_select;
DEALLOCATE PREPARE p_stmt_insert;
DEALLOCATE PREPARE p_stmt_update;
END|
--delimiter ;
--let $i=2
while ($i)
{
SET default_storage_engine=InnoDB;
if ($i==1)
{
SET default_storage_engine=MyISAM;
}
if ($i==0)
{
--echo
--echo ==========================
--echo = Test for MyISAM engine
--echo ==========================
--echo
}
if ($i==1)
{
--echo
--echo ==========================
--echo = Test for Innodb engine
--echo ==========================
}
--echo
--echo ============================
--echo = Test for simple DML and DDL
--echo ============================
--echo
--source query_response_time-rw-begin.inc
CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
b INT UNSIGNED NOT NULL DEFAULT 0);
INSERT INTO t1 (b) VALUES (1), (2);
UPDATE t1 SET b = 1;
SELECT * FROM t1;
DELETE FROM t1;
ALTER TABLE t1 ADD COLUMN (c INT);
DROP TABLE t1;
--source query_response_time-rw-end.inc
CREATE TABLE t1 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
b INT(10) UNSIGNED NOT NULL DEFAULT 0);
--echo
--echo ============================
--echo = Test for SELECT+DML
--echo ============================
--echo
--source query_response_time-rw-begin.inc
SELECT DML_FUNC();
--source query_response_time-rw-end.inc
--echo
--echo ============================
--echo = Test for nested calls
--echo ============================
--echo
--source query_response_time-rw-begin.inc
CALL NESTED_PROC();
--source query_response_time-rw-end.inc
--echo
--echo ==============================================
--echo = Test for PREPARE-EXECUTE in stored procedure
--echo ==============================================
--echo
--source query_response_time-rw-begin.inc
CALL PREPARE_EXECUTE_PROC();
--source query_response_time-rw-end.inc
--echo
--echo ============================
--echo = Test for 'PREPARE'
--echo ============================
--echo
--source query_response_time-rw-begin.inc
PREPARE rw_stmt FROM 'DELETE FROM t1';
PREPARE ro_stmt FROM 'SELECT * FROM t1';
PREPARE select_dml_stmt FROM 'SELECT DML_FUNC()';
PREPARE nested_call_stmt FROM 'CALL NESTED_PROC()';
--source query_response_time-rw-end.inc
--echo
--echo ============================
--echo = Test for 'EXECUTE'
--echo ============================
--echo
--source query_response_time-rw-begin.inc
EXECUTE rw_stmt;
EXECUTE ro_stmt;
EXECUTE select_dml_stmt;
EXECUTE nested_call_stmt;
--source query_response_time-rw-end.inc
--echo
--echo ============================
--echo = Test for 'DEALLOCATE PREPARE'
--echo ============================
--echo
--source query_response_time-rw-begin.inc
DEALLOCATE PREPARE rw_stmt;
DEALLOCATE PREPARE ro_stmt;
DEALLOCATE PREPARE select_dml_stmt;
DEALLOCATE PREPARE nested_call_stmt;
--source query_response_time-rw-end.inc
--echo
--echo ============================
--echo = Test for transactions
--echo ============================
--echo
--source query_response_time-rw-begin.inc
BEGIN;
SELECT * FROM t1;
COMMIT;
--source query_response_time-rw-end.inc
--source query_response_time-rw-begin.inc
BEGIN;
INSERT INTO t1 (b) VALUES (1), (2);
UPDATE t1 SET b = 1;
SELECT * FROM t1;
DELETE FROM t1;
COMMIT;
--source query_response_time-rw-end.inc
--source query_response_time-rw-begin.inc
BEGIN;
SELECT DML_FUNC();
CALL NESTED_PROC();
COMMIT;
--source query_response_time-rw-end.inc
--source query_response_time-rw-begin.inc
BEGIN;
INSERT INTO t1 (b) VALUES (1), (2);
UPDATE t1 SET b = 1;
ROLLBACK;
--source query_response_time-rw-end.inc
--echo
--echo ============================
--echo = Test for implicit commit
--echo ============================
--echo
SET autocommit = 0;
--source query_response_time-rw-begin.inc
INSERT INTO t1 (b) VALUES (1), (2);
CREATE INDEX ab ON t1 (a, b);
--source query_response_time-rw-end.inc
SET autocommit = 1;
--echo
--echo ============================
--echo = Test for trigger
--echo ============================
--echo
CREATE TABLE t2 (a INT UNSIGNED AUTO_INCREMENT PRIMARY KEY,
b INT UNSIGNED NOT NULL DEFAULT 0);
--source query_response_time-rw-begin.inc
--delimiter |
CREATE TRIGGER test_trigger BEFORE INSERT ON t1
FOR EACH ROW
BEGIN
INSERT INTO t2 SET b = NEW.b;
INSERT INTO t2 SET b = NEW.b;
END;
|
--delimiter ;
--source query_response_time-rw-end.inc
--source query_response_time-rw-begin.inc
INSERT INTO t1 (b) VALUES (1), (2);
--source query_response_time-rw-end.inc
DROP TABLE t1;
DROP TABLE t2;
--dec $i
}
SET default_storage_engine=default;
DROP FUNCTION DML_FUNC;
DROP PROCEDURE NESTED_PROC;
DROP PROCEDURE PREPARE_EXECUTE_PROC;
--echo #
--echo # MDEV-33931 QUERY_RESPONSE_TIME counts SHOW statements and I_S queries
--echo # as "writes"
--echo #
set global query_response_time_stats=1;
flush query_response_time_read_write;
select count(*) from information_schema.query_response_time_read_write where write_count > 0;
select count(*) from information_schema.query_response_time_read_write where write_count > 0;
select count(*) > 0 from information_schema.query_response_time_read_write where read_count > 0;
set global query_response_time_stats= 0;

2
plugin/query_response_time/mysql-test/query_response_time/query_response_time-stored.inc
View file

@ -2,8 +2,8 @@ SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
EVAL SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=$base;
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);

44
plugin/query_response_time/mysql-test/query_response_time/query_response_time-stored.result
View file

@ -5,14 +5,14 @@ SET SESSION query_response_time_exec_time_debug=t;
INSERT INTO t VALUES(1);
SET SESSION query_response_time_exec_time_debug=100000;
DELETE FROM t;
END^
END|
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1;
Warnings:
Warning 1292 Truncated incorrect query_response_time_range_base value: '1'
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -41,7 +41,7 @@ Variable_name Value
query_response_time_range_base 2
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000001 45 0.000000
0.000001 44 0.000000
0.000003 0 0.000000
0.000007 0 0.000000
0.000015 0 0.000000
@ -57,7 +57,7 @@ TIME COUNT TOTAL
0.015625 0 0.000000
0.031250 0 0.000000
0.062500 0 0.000000
0.125000 44 4.400000
0.125000 22 2.200000
0.250000 0 0.000000
0.500000 10 3.550000
1.000000 1 0.500000
@ -89,8 +89,8 @@ SET SESSION query_response_time_exec_time_debug=default;
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=2;
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -119,7 +119,7 @@ Variable_name Value
query_response_time_range_base 2
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000001 45 0.000000
0.000001 44 0.000000
0.000003 0 0.000000
0.000007 0 0.000000
0.000015 0 0.000000
@ -135,7 +135,7 @@ TIME COUNT TOTAL
0.015625 0 0.000000
0.031250 0 0.000000
0.062500 0 0.000000
0.125000 44 4.400000
0.125000 22 2.200000
0.250000 0 0.000000
0.500000 10 3.550000
1.000000 1 0.500000
@ -167,8 +167,8 @@ SET SESSION query_response_time_exec_time_debug=default;
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=10;
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -197,13 +197,13 @@ Variable_name Value
query_response_time_range_base 10
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000001 45 0.000000
0.000001 44 0.000000
0.000010 0 0.000000
0.000100 0 0.000000
0.001000 0 0.000000
0.010000 0 0.000000
0.100000 0 0.000000
1.000000 55 8.450000
1.000000 33 6.250000
10.000000 11 25.700000
100.000000 0 0.000000
1000.000000 0 0.000000
@ -215,8 +215,8 @@ SET SESSION query_response_time_exec_time_debug=default;
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=7;
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -245,13 +245,13 @@ Variable_name Value
query_response_time_range_base 7
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000001 45 0.000000
0.000001 44 0.000000
0.000008 0 0.000000
0.000059 0 0.000000
0.000416 0 0.000000
0.002915 0 0.000000
0.020408 0 0.000000
0.142857 44 4.400000
0.142857 22 2.200000
1.000000 11 4.050000
7.000000 11 25.700000
49.000000 0 0.000000
@ -266,8 +266,8 @@ SET SESSION query_response_time_exec_time_debug=default;
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=156;
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -296,9 +296,9 @@ Variable_name Value
query_response_time_range_base 156
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000041 45 0.000000
0.000041 44 0.000000
0.006410 0 0.000000
1.000000 55 8.450000
1.000000 33 6.250000
156.000000 11 25.700000
24336.000000 0 0.000000
3796416.000000 0 0.000000
@ -307,8 +307,8 @@ SET SESSION query_response_time_exec_time_debug=default;
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1000;
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -337,9 +337,9 @@ Variable_name Value
query_response_time_range_base 1000
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000001 45 0.000000
0.000001 44 0.000000
0.001000 0 0.000000
1.000000 55 8.450000
1.000000 33 6.250000
1000.000000 11 25.700000
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
@ -349,8 +349,8 @@ SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1001;
Warnings:
Warning 1292 Truncated incorrect query_response_time_range_base value: '1001'
SET GLOBAL query_response_time_flush=1;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
FLUSH QUERY_RESPONSE_TIME;
CALL test_f(310000);
CALL test_f(320000);
CALL test_f(330000);
@ -379,9 +379,9 @@ Variable_name Value
query_response_time_range_base 1000
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
TIME COUNT TOTAL
0.000001 45 0.000000
0.000001 44 0.000000
0.001000 0 0.000000
1.000000 55 8.450000
1.000000 33 6.250000
1000.000000 11 25.700000
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG

6
plugin/query_response_time/mysql-test/query_response_time/query_response_time-stored.test
View file

@ -11,15 +11,15 @@ if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
CREATE TABLE t(a INT);
delimiter ^;
--delimiter |
CREATE PROCEDURE test_f(t INT)
BEGIN
SET SESSION query_response_time_exec_time_debug=t;
INSERT INTO t VALUES(1);
SET SESSION query_response_time_exec_time_debug=100000;
DELETE FROM t;
END^
delimiter ;^
END|
--delimiter ;
--let base=1
--source query_response_time-stored.inc

17
plugin/query_response_time/mysql-test/query_response_time/query_response_time.inc
View file

@ -3,11 +3,12 @@ SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
EVAL SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=$base;
FLUSH QUERY_RESPONSE_TIME;
# Following two queries check works of FLUSH and
# Following two queries check works of FLUSH and
# respecting of "QUERY_RESPONSE_TIME_STATS" variable (see launchpad bug #855312)
SELECT * FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
--disable_query_log
SET SESSION query_response_time_exec_time_debug=310000; SELECT 1;
SET SESSION query_response_time_exec_time_debug=320000; SELECT 1;
SET SESSION query_response_time_exec_time_debug=330000; SELECT 1;
@ -31,11 +32,25 @@ SET SESSION query_response_time_exec_time_debug=3100000; SELECT 1;
SET SESSION query_response_time_exec_time_debug=4100000; SELECT 1;
SET SESSION query_response_time_exec_time_debug=5100000; SELECT 1;
SET SESSION query_response_time_exec_time_debug=310000; INSERT into t1 values();
SET SESSION query_response_time_exec_time_debug=370000; INSERT into t1 values();
SET SESSION query_response_time_exec_time_debug=130000; INSERT into t1 values();
SET SESSION query_response_time_exec_time_debug=5100000; INSERT into t1 values();
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
--enable_query_log
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
SHOW QUERY_RESPONSE_TIME;
if ($base == 1000)
{
# We do no do this for every query to have smaller result file
SHOW QUERY_RESPONSE_TIME_READ;
SHOW QUERY_RESPONSE_TIME_WRITE;
SHOW QUERY_RESPONSE_TIME_READ_WRITE;
}
SET SESSION query_response_time_exec_time_debug=default;

432
plugin/query_response_time/mysql-test/query_response_time/query_response_time.result
View file

@ -1,3 +1,4 @@
create table t1 (a int, b int);
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=1;
@ -51,102 +52,56 @@ TIME COUNT TOTAL
8388608.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 2
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000001 24 0.000000
0.000001 28 0.000000
0.000003 0 0.000000
0.000007 0 0.000000
0.000015 0 0.000000
@ -163,12 +118,12 @@ Time Count Total
0.031250 0 0.000000
0.062500 0 0.000000
0.125000 0 0.000000
0.250000 0 0.000000
0.500000 10 3.550000
0.250000 1 0.130000
0.500000 12 4.230000
1.000000 1 0.500000
2.000000 5 6.500000
4.000000 4 10.000000
8.000000 2 9.200000
8.000000 3 14.300000
16.000000 0 0.000000
32.000000 0 0.000000
64.000000 0 0.000000
@ -242,102 +197,56 @@ TIME COUNT TOTAL
8388608.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 2
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000001 24 0.000000
0.000001 28 0.000000
0.000003 0 0.000000
0.000007 0 0.000000
0.000015 0 0.000000
@ -354,12 +263,12 @@ Time Count Total
0.031250 0 0.000000
0.062500 0 0.000000
0.125000 0 0.000000
0.250000 0 0.000000
0.500000 10 3.550000
0.250000 1 0.130000
0.500000 12 4.230000
1.000000 1 0.500000
2.000000 5 6.500000
4.000000 4 10.000000
8.000000 2 9.200000
8.000000 3 14.300000
16.000000 0 0.000000
32.000000 0 0.000000
64.000000 0 0.000000
@ -403,109 +312,63 @@ TIME COUNT TOTAL
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 10
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000001 24 0.000000
0.000001 28 0.000000
0.000010 0 0.000000
0.000100 0 0.000000
0.001000 0 0.000000
0.010000 0 0.000000
0.100000 0 0.000000
1.000000 11 4.050000
10.000000 11 25.700000
1.000000 14 4.860000
10.000000 12 30.800000
100.000000 0 0.000000
1000.000000 0 0.000000
10000.000000 0 0.000000
@ -537,110 +400,64 @@ TIME COUNT TOTAL
5764801.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 7
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000001 24 0.000000
0.000001 28 0.000000
0.000008 0 0.000000
0.000059 0 0.000000
0.000416 0 0.000000
0.002915 0 0.000000
0.020408 0 0.000000
0.142857 0 0.000000
1.000000 11 4.050000
7.000000 11 25.700000
0.142857 1 0.130000
1.000000 13 4.730000
7.000000 12 30.800000
49.000000 0 0.000000
343.000000 0 0.000000
2401.000000 0 0.000000
@ -664,105 +481,59 @@ TIME COUNT TOTAL
3796416.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 156
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000041 24 0.000000
0.000041 28 0.000000
0.006410 0 0.000000
1.000000 11 4.050000
156.000000 11 25.700000
1.000000 14 4.860000
156.000000 12 30.800000
24336.000000 0 0.000000
3796416.000000 0 0.000000
TOO LONG 0 TOO LONG
@ -780,107 +551,85 @@ TIME COUNT TOTAL
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 1000
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000001 24 0.000000
0.000001 28 0.000000
0.001000 0 0.000000
1.000000 14 4.860000
1000.000000 12 30.800000
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SHOW QUERY_RESPONSE_TIME_READ;
Time Count Total
0.000001 28 0.000000
0.001000 0 0.000000
1.000000 11 4.050000
1000.000000 11 25.700000
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SHOW QUERY_RESPONSE_TIME_WRITE;
Time Count Total
0.000001 0 0.000000
0.001000 0 0.000000
1.000000 3 0.810000
1000.000000 1 5.100000
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SHOW QUERY_RESPONSE_TIME_READ_WRITE;
Time Read_count Read_total Write_Count Write_Total
0.000001 28 0.000000 0 0.000000
0.001000 0 0.000000 0 0.000000
1.000000 11 4.050000 3 0.810000
1000.000000 11 25.700000 1 5.100000
1000000.000000 0 0.000000 0 0.000000
TOO LONG 0 TOO LONG 0 0.000000
SET SESSION query_response_time_exec_time_debug=default;
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
@ -897,107 +646,102 @@ TIME COUNT TOTAL
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SET GLOBAL QUERY_RESPONSE_TIME_STATS=1;
SET SESSION query_response_time_exec_time_debug=310000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=320000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=330000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=340000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=350000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=360000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=370000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=380000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=390000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1200000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=1400000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2300000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=2500000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=3100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=4100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=5100000;
SELECT 1;
1
1
SET SESSION query_response_time_exec_time_debug=100000;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=0;
SHOW GLOBAL VARIABLES where Variable_name like 'QUERY_RESPONSE_TIME_RANGE_BASE';
Variable_name Value
query_response_time_range_base 1000
SHOW QUERY_RESPONSE_TIME;
Time Count Total
0.000001 24 0.000000
0.000001 28 0.000000
0.001000 0 0.000000
1.000000 11 4.050000
1000.000000 11 25.700000
1.000000 14 4.860000
1000.000000 12 30.800000
1000000.000000 0 0.000000
TOO LONG 0 TOO LONG
SET SESSION query_response_time_exec_time_debug=default;
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
drop table t1;
#
# MDEV-34031 FLUSH QUERY_RESPONSE_TIME_WRITE also flushes READ, and
# vice versa
#
flush query_response_time;
set query_response_time_session_stats=on;
create table t1 (a int);
insert into t1 values (1);
insert into t1 values (2);
select * from t1;
a
1
2
select sum(count) from information_schema.query_response_time_read;
sum(count)
2
select sum(count) from information_schema.query_response_time_write;
sum(count)
3
flush query_response_time_write;
select sum(count) from information_schema.query_response_time_read;
sum(count)
4
select sum(count) from information_schema.query_response_time_write;
sum(count)
0
set @save_query_response_time_range_base=@@global.query_response_time_range_base;
select @@global.query_response_time_range_base;
@@global.query_response_time_range_base
10
set @@global.query_response_time_range_base=2;
flush query_response_time_write;
select sum(count) from information_schema.query_response_time_read;
sum(count)
0
select sum(count) from information_schema.query_response_time_write;
sum(count)
0
set @@global.query_response_time_range_base=@save_query_response_time_range_base;
drop table t1;

29
plugin/query_response_time/mysql-test/query_response_time/query_response_time.test
View file

@ -8,6 +8,7 @@ if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
--skip Test requires: ps-protocol/sp-protocol/cursor-protocol/view-protocol disabled
}
create table t1 (a int, b int);
--let base=1
--source query_response_time.inc
@ -26,3 +27,31 @@ if (`SELECT $PS_PROTOCOL + $SP_PROTOCOL + $CURSOR_PROTOCOL
SET GLOBAL QUERY_RESPONSE_TIME_RANGE_BASE=default;
SET GLOBAL QUERY_RESPONSE_TIME_STATS=default;
drop table t1;
--echo #
--echo # MDEV-34031 FLUSH QUERY_RESPONSE_TIME_WRITE also flushes READ, and
--echo # vice versa
--echo #
flush query_response_time;
set query_response_time_session_stats=on;
create table t1 (a int);
insert into t1 values (1);
insert into t1 values (2);
select * from t1;
select sum(count) from information_schema.query_response_time_read;
select sum(count) from information_schema.query_response_time_write;
flush query_response_time_write;
select sum(count) from information_schema.query_response_time_read;
select sum(count) from information_schema.query_response_time_write;
set @save_query_response_time_range_base=@@global.query_response_time_range_base;
select @@global.query_response_time_range_base;
set @@global.query_response_time_range_base=2;
flush query_response_time_write;
select sum(count) from information_schema.query_response_time_read;
select sum(count) from information_schema.query_response_time_write;
set @@global.query_response_time_range_base=@save_query_response_time_range_base;
drop table t1;

126
plugin/query_response_time/mysql-test/query_response_time/session_toggle.result Normal file
View file

@ -0,0 +1,126 @@
#
# Tests for query_response_time_session_stats variable
#
SET @saved_query_response_time_stats = @@GLOBAL.query_response_time_stats;
SET @saved_query_response_time_flush = @@GLOBAL.query_response_time_flush;
SET GLOBAL query_response_time_flush= 'ON';
SELECT SUM(COUNT),1 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 1
0 1
# global: ON, session: default(GLOBAL): must be logged
SET GLOBAL query_response_time_stats= 'ON';
SELECT 1;
1
1
SELECT SUM(COUNT),2 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 2
2 2
# global: OFF, session: default(GLOBAL): must not be logged
SET GLOBAL query_response_time_stats= 'OFF';
SELECT 1;
1
1
SELECT SUM(COUNT),3 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 3
3 3
# global: ON, session: GLOBAL: must be logged
SET GLOBAL query_response_time_stats= 'ON';
SET SESSION query_response_time_session_stats= 'GLOBAL';
SELECT 1;
1
1
SELECT SUM(COUNT),4 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 4
6 4
# global: OFF, session: GLOBAL: must not be logged
SET GLOBAL query_response_time_stats= 'OFF';
SELECT 1;
1
1
SELECT SUM(COUNT),5 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 5
7 5
# global: OFF, session: OFF: must not be logged
SET SESSION query_response_time_session_stats= 'OFF';
SELECT 1;
1
1
SELECT SUM(COUNT),6 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 6
7 6
# global: ON, session: OFF: must not be logged
SELECT 1;
1
1
SELECT SUM(COUNT),7 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 7
7 7
# global: ON: session: ON: must be logged
SET SESSION query_response_time_session_stats= 'ON';
SELECT 1;
1
1
SELECT SUM(COUNT),8 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 8
9 8
# global: OFF: session: ON: must be logged
SET GLOBAL query_response_time_stats= 'OFF';
SELECT 1;
1
1
SELECT SUM(COUNT),9 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 9
12 9
connect con2,localhost,root,,;
connect con3,localhost,root,,;
connection con2;
# 2nd connection: global OFF, session: default(GLOBAL): must not be logged
SELECT 1;
1
1
SELECT SUM(COUNT),10 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 10
13 10
FLUSH TABLES;
connection con3;
# 3rd connection: global OFF, session: OFF: must not be logged
SET SESSION query_response_time_session_stats= 'OFF';
SELECT 1;
1
1
SELECT SUM(COUNT),11 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 11
13 11
connection default;
# 1st connection: global ON, session: ON: must be logged
SET GLOBAL query_response_time_stats= 'ON';
SELECT 1;
1
1
SELECT SUM(COUNT),12 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 12
15 12
FLUSH TABLES;
connection con2;
# 2nd connection: global ON, session: default(GLOBAL): must be logged
SELECT 1;
1
1
SELECT SUM(COUNT),13 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 13
17 13
FLUSH TABLES;
connection con3;
# 3rd connection: global ON: session: OFF: must not be logged
SELECT 1;
1
1
SELECT SUM(COUNT),14 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
SUM(COUNT) 14
18 14
disconnect con2;
disconnect con3;
connection default;
# Cleanup
SET GLOBAL query_response_time_flush = @saved_query_response_time_flush;
SET GLOBAL query_response_time_stats = @saved_query_response_time_stats;

113
plugin/query_response_time/mysql-test/query_response_time/session_toggle.test Normal file
View file

@ -0,0 +1,113 @@
--source include/have_debug_sync.inc
--disable_ps_protocol
--echo #
--echo # Tests for query_response_time_session_stats variable
--echo #
SET @saved_query_response_time_stats = @@GLOBAL.query_response_time_stats;
SET @saved_query_response_time_flush = @@GLOBAL.query_response_time_flush;
SET GLOBAL query_response_time_flush= 'ON';
SELECT SUM(COUNT),1 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: ON, session: default(GLOBAL): must be logged
SET GLOBAL query_response_time_stats= 'ON';
SELECT 1;
SELECT SUM(COUNT),2 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: OFF, session: default(GLOBAL): must not be logged
SET GLOBAL query_response_time_stats= 'OFF';
SELECT 1;
SELECT SUM(COUNT),3 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: ON, session: GLOBAL: must be logged
SET GLOBAL query_response_time_stats= 'ON';
SET SESSION query_response_time_session_stats= 'GLOBAL';
SELECT 1;
SELECT SUM(COUNT),4 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: OFF, session: GLOBAL: must not be logged
SET GLOBAL query_response_time_stats= 'OFF';
SELECT 1;
SELECT SUM(COUNT),5 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: OFF, session: OFF: must not be logged
SET SESSION query_response_time_session_stats= 'OFF';
SELECT 1;
SELECT SUM(COUNT),6 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: ON, session: OFF: must not be logged
SELECT 1;
SELECT SUM(COUNT),7 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: ON: session: ON: must be logged
SET SESSION query_response_time_session_stats= 'ON';
SELECT 1;
SELECT SUM(COUNT),8 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
--echo # global: OFF: session: ON: must be logged
SET GLOBAL query_response_time_stats= 'OFF';
SELECT 1;
SELECT SUM(COUNT),9 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
connect(con2,localhost,root,,);
connect(con3,localhost,root,,);
connection con2;
--echo # 2nd connection: global OFF, session: default(GLOBAL): must not be logged
SELECT 1;
SELECT SUM(COUNT),10 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
# Ensure mysql_audit_general() is called for the above call
FLUSH TABLES;
connection con3;
--echo # 3rd connection: global OFF, session: OFF: must not be logged
SET SESSION query_response_time_session_stats= 'OFF';
SELECT 1;
SELECT SUM(COUNT),11 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
connection default;
--echo # 1st connection: global ON, session: ON: must be logged
SET GLOBAL query_response_time_stats= 'ON';
SELECT 1;
SELECT SUM(COUNT),12 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
FLUSH TABLES;
connection con2;
--echo # 2nd connection: global ON, session: default(GLOBAL): must be logged
SELECT 1;
SELECT SUM(COUNT),13 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
# Ensure mysql_audit_general() is called for the above call
FLUSH TABLES;
connection con3;
--echo # 3rd connection: global ON: session: OFF: must not be logged
SELECT 1;
SELECT SUM(COUNT),14 FROM INFORMATION_SCHEMA.QUERY_RESPONSE_TIME;
disconnect con2;
disconnect con3;
connection default;
--echo # Cleanup
SET GLOBAL query_response_time_flush = @saved_query_response_time_flush;
SET GLOBAL query_response_time_stats = @saved_query_response_time_stats;
--enable_ps_protocol

2
plugin/query_response_time/mysql-test/query_response_time/suite.opt
View file

@ -1 +1 @@
--plugin-load-add=$QUERY_RESPONSE_TIME_SO --plugin-query-response-time=ON --plugin-query-response-time-audit=ON
--plugin-load-add=$QUERY_RESPONSE_TIME_SO --plugin-query-response-time=ON --plugin-query-response-time-audit=ON --plugin-query-response-time-read=ON --plugin-query-response-time-write=ON --plugin-query-response-time-read-write=ON

1
plugin/query_response_time/mysql-test/query_response_time/suite.pm
View file

@ -11,4 +11,3 @@ return "Not run for embedded server" if $::opt_embedded_server;
sub is_default { 1 }
bless { };

208
plugin/query_response_time/plugin.cc
View file

@ -1,4 +1,5 @@
/* Copyright (C) 2013 Percona and Sergey Vojtovich
Copyright (C) 2023 MariaDB Foundation
This program is free software; you can redistribute it and/or modify
it under the terms of the GNU General Public License as published by
@ -20,12 +21,12 @@
#include <sql_show.h>
#include <mysql/plugin_audit.h>
#include "query_response_time.h"
#include <sql_parse.h>
ulong opt_query_response_time_range_base= QRT_DEFAULT_BASE;
my_bool opt_query_response_time_stats= 0;
static my_bool opt_query_response_time_flush= 0;
static my_bool inited= 0;
static void query_response_time_flush_update(
MYSQL_THD thd __attribute__((unused)),
@ -33,23 +34,37 @@ static void query_response_time_flush_update(
void *tgt __attribute__((unused)),
const void *save __attribute__((unused)))
{
query_response_time_flush();
query_response_time_flush_all();
}
enum session_stat
{
session_stat_global,
session_stat_on,
session_stat_off
};
static const char *session_stat_names[]= {"GLOBAL", "ON", "OFF", NullS};
static TYPELIB session_stat_typelib= { array_elements(session_stat_names) - 1,
"", session_stat_names, NULL};
static MYSQL_SYSVAR_ULONG(range_base, opt_query_response_time_range_base,
PLUGIN_VAR_RQCMDARG,
"Select base of log for query_response_time ranges. WARNING: variable "
"change affect only after flush",
"Select base of log for query_response_time ranges. "
"WARNING: change of this variable take effect only after next "
"FLUSH QUERY_RESPONSE_TIME execution. Changing the variable will "
"flush both read and writes on the next FLUSH",
NULL, NULL, QRT_DEFAULT_BASE, 2, QRT_MAXIMUM_BASE, 1);
static MYSQL_SYSVAR_BOOL(stats, opt_query_response_time_stats,
PLUGIN_VAR_OPCMDARG,
"Enable or disable query response time statisics collecting",
"Enable or disable query response time statistics collecting",
NULL, NULL, FALSE);
static MYSQL_SYSVAR_BOOL(flush, opt_query_response_time_flush,
PLUGIN_VAR_NOCMDOPT,
"Update of this variable flushes statistics and re-reads "
"query_response_time_range_base",
"query_response_time_range_base. Deprecated. "
"Use \"FLUSH query_response_time\" instead",
NULL, query_response_time_flush_update, FALSE);
#ifndef DBUG_OFF
static MYSQL_THDVAR_ULONGLONG(exec_time_debug, PLUGIN_VAR_NOCMDOPT,
@ -57,7 +72,11 @@ static MYSQL_THDVAR_ULONGLONG(exec_time_debug, PLUGIN_VAR_NOCMDOPT,
"the actual execution time. Used only for debugging",
NULL, NULL, 0, 0, LONG_TIMEOUT, 1);
#endif
static MYSQL_THDVAR_ENUM(session_stats, PLUGIN_VAR_RQCMDARG,
"Controls query response time statistics collection for the current "
"session: ON - enable, OFF - disable, GLOBAL (default) - use "
"query_response_time_stats value", NULL, NULL,
session_stat_global, &session_stat_typelib);
static struct st_mysql_sys_var *query_response_time_info_vars[]=
{
@ -67,10 +86,10 @@ static struct st_mysql_sys_var *query_response_time_info_vars[]=
#ifndef DBUG_OFF
MYSQL_SYSVAR(exec_time_debug),
#endif
MYSQL_SYSVAR(session_stats),
NULL
};
namespace Show {
ST_FIELD_INFO query_response_time_fields_info[] =
@ -81,22 +100,71 @@ ST_FIELD_INFO query_response_time_fields_info[] =
CEnd()
};
ST_FIELD_INFO query_response_time_rw_fields_info[] =
{
Column("TIME", Varchar(QRT_TIME_STRING_LENGTH), NOT_NULL, "Time"),
Column("READ_COUNT", ULong(), NOT_NULL, "Read_count"),
Column("READ_TOTAL", Varchar(QRT_TIME_STRING_LENGTH), NOT_NULL, "Read_total"),
Column("WRITE_COUNT", ULong(), NOT_NULL,
"Write_Count"),
Column("WRITE_TOTAL", Varchar(QRT_TIME_STRING_LENGTH),NOT_NULL,
"Write_Total"),
CEnd()
};
} // namespace Show
static int query_response_time_info_init(void *p)
static int query_response_time_init(void *p)
{
ST_SCHEMA_TABLE *i_s_query_response_time= (ST_SCHEMA_TABLE *) p;
i_s_query_response_time->fields_info= Show::query_response_time_fields_info;
i_s_query_response_time->fill_table= query_response_time_fill;
i_s_query_response_time->reset_table= query_response_time_flush;
i_s_query_response_time->reset_table= query_response_time_flush_all;
query_response_time_init();
inited= 1;
return 0;
}
static int query_response_time_read_init(void *p)
{
ST_SCHEMA_TABLE *i_s_query_response_time= (ST_SCHEMA_TABLE *) p;
i_s_query_response_time->fields_info= Show::query_response_time_fields_info;
i_s_query_response_time->fill_table= query_response_time_fill_read;
i_s_query_response_time->reset_table= query_response_time_flush_read;
query_response_time_init();
return 0;
}
static int query_response_time_write_init(void *p)
{
ST_SCHEMA_TABLE *i_s_query_response_time= (ST_SCHEMA_TABLE *) p;
i_s_query_response_time->fields_info= Show::query_response_time_fields_info;
i_s_query_response_time->fill_table= query_response_time_fill_write;
i_s_query_response_time->reset_table= query_response_time_flush_write;
query_response_time_init();
return 0;
}
static int query_response_time_info_deinit(void *arg __attribute__((unused)))
static int query_response_time_read_write_init(void *p)
{
ST_SCHEMA_TABLE *i_s_query_response_time= (ST_SCHEMA_TABLE *) p;
i_s_query_response_time->fields_info= Show::query_response_time_rw_fields_info;
i_s_query_response_time->fill_table= query_response_time_fill_read_write;
i_s_query_response_time->reset_table= query_response_time_flush_all;
query_response_time_init();
return 0;
}
static int query_response_time_deinit_main(void *arg __attribute__((unused)))
{
opt_query_response_time_stats= 0;
query_response_time_free();
inited= 0;
return 0;
}
static int query_response_time_deinit(void *arg __attribute__((unused)))
{
query_response_time_free();
return 0;
}
@ -106,6 +174,52 @@ static struct st_mysql_information_schema query_response_time_info_descriptor=
{ MYSQL_INFORMATION_SCHEMA_INTERFACE_VERSION };
static bool query_response_time_should_log(MYSQL_THD thd)
{
/*
We don't log sub statements and in this the time will be accounted
multiple times (both for the sub statement and the real statement.
*/
if (!inited || thd->in_sub_stmt)
return 0;
const enum session_stat session_stat_val=
static_cast<session_stat>(THDVAR(thd, session_stats));
if (!((session_stat_val == session_stat_on) ||
(session_stat_val == session_stat_global &&
opt_query_response_time_stats)))
return 0;
if (!thd->lex)
{
/*
This can only happen for stored procedures/functions that failed
when calling sp_lex_keeper::validate_lex_and_exec_core(). In this
case the statement was never executed.
*/
return 0;
}
if (thd->lex->sql_command == SQLCOM_CALL)
{
/*
For stored procedures we have already handled all statements.
Ignore the call which contains the time for all sub statements.
*/
return 0;
}
if (thd->lex->sql_command == SQLCOM_FLUSH)
{
/*
Ignore FLUSH as we don't want FLUSH query_response_time to affect
statistics.
*/
return 0;
}
return 1;
}
static void query_response_time_audit_notify(MYSQL_THD thd,
unsigned int event_class,
const void *event)
@ -113,16 +227,27 @@ static void query_response_time_audit_notify(MYSQL_THD thd,
const struct mysql_event_general *event_general=
(const struct mysql_event_general *) event;
DBUG_ASSERT(event_class == MYSQL_AUDIT_GENERAL_CLASS);
if (event_general->event_subclass == MYSQL_AUDIT_GENERAL_STATUS &&
opt_query_response_time_stats)
query_response_time_should_log(thd))
{
QUERY_TYPE query_type= (thd->stmt_changes_data ? WRITE : READ);
#ifndef DBUG_OFF
if (THDVAR(thd, exec_time_debug))
query_response_time_collect(thd->lex->sql_command != SQLCOM_SET_OPTION ?
{
/* This code is only here for MTR tests */
query_response_time_collect(query_type,
thd->lex->sql_command != SQLCOM_SET_OPTION ?
THDVAR(thd, exec_time_debug) : 0);
}
else
#endif
query_response_time_collect(thd->utime_after_query - thd->utime_after_lock);
{
DBUG_ASSERT(thd->utime_after_query >= thd->utime_after_lock);
query_response_time_collect(query_type,
thd->utime_after_query -
thd->utime_after_lock);
}
}
}
@ -142,12 +267,57 @@ maria_declare_plugin(query_response_time)
"Percona and Sergey Vojtovich",
"Query Response Time Distribution INFORMATION_SCHEMA Plugin",
PLUGIN_LICENSE_GPL,
query_response_time_info_init,
query_response_time_info_deinit,
query_response_time_init,
query_response_time_deinit_main,
0x0100,
NULL,
query_response_time_info_vars,
"1.0",
"2.0",
MariaDB_PLUGIN_MATURITY_STABLE
},
{
MYSQL_INFORMATION_SCHEMA_PLUGIN,
&query_response_time_info_descriptor,
"QUERY_RESPONSE_TIME_READ",
"Percona and Sergey Vojtovich",
"Query Response Time Distribution INFORMATION_SCHEMA Plugin",
PLUGIN_LICENSE_GPL,
query_response_time_read_init,
query_response_time_deinit,
0x0100,
NULL,
NULL,
"2.0",
MariaDB_PLUGIN_MATURITY_STABLE
},
{
MYSQL_INFORMATION_SCHEMA_PLUGIN,
&query_response_time_info_descriptor,
"QUERY_RESPONSE_TIME_WRITE",
"Percona and Sergey Vojtovich",
"Query Response Time Distribution INFORMATION_SCHEMA Plugin",
PLUGIN_LICENSE_GPL,
query_response_time_write_init,
query_response_time_deinit,
0x0100,
NULL,
NULL,
"2.0",
MariaDB_PLUGIN_MATURITY_STABLE
},
{
MYSQL_INFORMATION_SCHEMA_PLUGIN,
&query_response_time_info_descriptor,
"QUERY_RESPONSE_TIME_READ_WRITE",
"Monty",
"Query Response Time Distribution INFORMATION_SCHEMA Plugin",
PLUGIN_LICENSE_GPL,
query_response_time_read_write_init,
query_response_time_deinit,
0x0100,
NULL,
NULL,
"2.0",
MariaDB_PLUGIN_MATURITY_STABLE
},
{
@ -162,7 +332,7 @@ maria_declare_plugin(query_response_time)
0x0100,
NULL,
NULL,
"1.0",
"2.0",
MariaDB_PLUGIN_MATURITY_STABLE
}
maria_declare_plugin_end;

161
plugin/query_response_time/query_response_time.cc
View file

@ -137,43 +137,75 @@ private:
};
static
void print_time(char* buffer, std::size_t buffer_size, const char* format,
uint64 value)
size_t print_time(char* buffer, std::size_t buffer_size, const char* format,
uint64 value)
{
ulonglong second= (value / MILLION);
ulonglong microsecond= (value % MILLION);
my_snprintf(buffer, buffer_size, format, second, microsecond);
return my_snprintf(buffer, buffer_size, format, second, microsecond);
}
class time_collector
{
utility *m_utility;
Atomic_counter<uint32_t> m_count[OVERALL_POWER_COUNT + 1];
Atomic_counter<uint64_t> m_total[OVERALL_POWER_COUNT + 1];
/*
Counters for each query type. See QUERY_TYPE
*/
Atomic_counter<uint32_t> m_count[QUERY_TYPES][OVERALL_POWER_COUNT + 1];
Atomic_counter<uint64_t> m_total[QUERY_TYPES][OVERALL_POWER_COUNT + 1];
public:
time_collector(utility& u): m_utility(&u) { flush(); }
time_collector(utility& u): m_utility(&u) { flush_all(); }
~time_collector() = default;
uint32_t count(uint index) { return m_count[index]; }
uint64_t total(uint index) { return m_total[index]; }
void flush()
uint32_t count(QUERY_TYPE type, uint index) { return m_count[type][index]; }
uint64_t total(QUERY_TYPE type, uint index) { return m_total[type][index]; }
void flush(QUERY_TYPE type)
{
for (auto i= 0; i < OVERALL_POWER_COUNT + 1; i++)
{
m_count[i]= 0;
m_total[i]= 0;
switch (type) {
case ANY: flush_all(); break;
case READ: flush_read(); break;
case WRITE: flush_write(); break;
}
}
void collect(uint64_t time)
void flush_all()
{
memset((void*)&m_count,0,sizeof(m_count));
memset((void*)&m_total,0,sizeof(m_total));
}
void flush_read()
{
memset((void*)&m_count[READ],0,sizeof(m_count[READ]));
memset((void*)&m_total[READ],0,sizeof(m_total[READ]));
update_total();
}
void flush_write()
{
memset((void*)&m_count[WRITE],0,sizeof(m_count[WRITE]));
memset((void*)&m_total[WRITE],0,sizeof(m_total[WRITE]));
update_total();
}
void update_total()
{
int count, i;
for (i=0, count= m_utility->bound_count(); i < count; ++i)
{
m_count[0][i]= m_count[1][i]+m_count[2][i];
m_total[0][i]= m_total[1][i]+m_total[2][i];
}
}
void collect(QUERY_TYPE type, uint64_t time)
{
DBUG_ASSERT(type != ANY);
int i= 0;
for(int count= m_utility->bound_count(); count > i; ++i)
{
if(m_utility->bound(i) > time)
if (m_utility->bound(i) > time)
{
m_count[i]++;
m_total[i]+= time;
break;
m_count[0][i]++;
m_total[0][i]+= time;
m_count[type][i]++;
m_total[type][i]+= time;
return;
}
}
}
@ -185,14 +217,21 @@ public:
collector() : m_time(m_utility)
{
m_utility.setup(DEFAULT_BASE);
m_time.flush_all();
}
public:
void flush()
void flush(QUERY_TYPE type)
{
m_utility.setup(opt_query_response_time_range_base);
m_time.flush();
if (opt_query_response_time_range_base != m_utility.base())
{
/* We have to flush everything if base changes */
type= ANY;
m_utility.setup(opt_query_response_time_range_base);
}
m_time.flush(type);
}
int fill(THD* thd, TABLE_LIST *tables, COND *cond)
int fill(QUERY_TYPE type, THD* thd, TABLE_LIST *tables, COND *cond,
bool extra_fields)
{
DBUG_ENTER("fill_schema_query_response_time");
TABLE *table= static_cast<TABLE*>(tables->table);
@ -201,21 +240,32 @@ public:
{
char time[TIME_STRING_BUFFER_LENGTH];
char total[TOTAL_STRING_BUFFER_LENGTH];
size_t time_length, total_length;
if(i == bound_count())
{
assert(sizeof(TIME_OVERFLOW) <= TIME_STRING_BUFFER_LENGTH);
assert(sizeof(TIME_OVERFLOW) <= TOTAL_STRING_BUFFER_LENGTH);
memcpy(time,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
memcpy(total,TIME_OVERFLOW,sizeof(TIME_OVERFLOW));
time_length= total_length= sizeof(TIME_OVERFLOW)-1;
}
else
{
print_time(time, sizeof(time), TIME_STRING_FORMAT, this->bound(i));
print_time(total, sizeof(total), TOTAL_STRING_FORMAT, this->total(i));
time_length= print_time(time, sizeof(time), TIME_STRING_FORMAT,
this->bound(i));
total_length= print_time(total, sizeof(total), TOTAL_STRING_FORMAT,
this->total(type, i));
}
fields[0]->store(time, time_length, system_charset_info);
fields[1]->store((longlong) this->count(type, i), true);
fields[2]->store(total, total_length, system_charset_info);
if (extra_fields)
{
fields[3]->store((longlong) this->count(WRITE, i), true);
total_length= print_time(total, sizeof(total), TOTAL_STRING_FORMAT,
this->total(WRITE, i));
fields[4]->store(total, total_length, system_charset_info);
}
fields[0]->store(time,strlen(time),system_charset_info);
fields[1]->store((longlong)this->count(i),true);
fields[2]->store(total,strlen(total),system_charset_info);
if (schema_table_store_record(thd, table))
{
DBUG_RETURN(1);
@ -223,9 +273,9 @@ public:
}
DBUG_RETURN(0);
}
void collect(ulonglong time)
void collect(QUERY_TYPE type, ulonglong time)
{
m_time.collect(time);
m_time.collect(type, time);
}
uint bound_count() const
{
@ -235,13 +285,13 @@ public:
{
return m_utility.bound(index);
}
ulonglong count(uint index)
ulonglong count(QUERY_TYPE type, uint index)
{
return m_time.count(index);
return m_time.count(type, index);
}
ulonglong total(uint index)
ulonglong total(QUERY_TYPE type, uint index)
{
return m_time.total(index);
return m_time.total(type, index);
}
private:
utility m_utility;
@ -254,25 +304,56 @@ static collector g_collector;
void query_response_time_init()
{
query_response_time_flush_all();
}
void query_response_time_free()
{
query_response_time::g_collector.flush();
query_response_time::g_collector.flush(ANY);
}
int query_response_time_flush()
int query_response_time_flush_all()
{
query_response_time::g_collector.flush();
query_response_time::g_collector.flush(ANY);
return 0;
}
void query_response_time_collect(ulonglong query_time)
int query_response_time_flush_read()
{
query_response_time::g_collector.collect(query_time);
query_response_time::g_collector.flush(READ);
return 0;
}
int query_response_time_fill(THD* thd, TABLE_LIST *tables, COND *cond)
int query_response_time_flush_write()
{
return query_response_time::g_collector.fill(thd,tables,cond);
query_response_time::g_collector.flush(WRITE);
return 0;
}
void query_response_time_collect(QUERY_TYPE type, ulonglong query_time)
{
query_response_time::g_collector.collect(type, query_time);
}
int query_response_time_fill(THD *thd, TABLE_LIST *tables, COND *cond)
{
return query_response_time::g_collector.fill(ANY, thd,tables, cond, 0);
}
int query_response_time_fill_read(THD *thd, TABLE_LIST *tables, COND *cond)
{
return query_response_time::g_collector.fill(READ, thd, tables, cond, 0);
}
int query_response_time_fill_write(THD *thd, TABLE_LIST *tables, COND *cond)
{
return query_response_time::g_collector.fill(WRITE, thd, tables, cond, 0);
}
int query_response_time_fill_read_write(THD *thd, TABLE_LIST *tables,
COND *cond)
{
/* write will also be filled as extra fields is 1 */
return query_response_time::g_collector.fill(READ, thd, tables, cond, 1);
}
#endif // HAVE_RESPONSE_TIME_DISTRIBUTION

30
plugin/query_response_time/query_response_time.h
View file

@ -53,12 +53,32 @@
extern ST_SCHEMA_TABLE query_response_time_table;
enum QUERY_TYPE
{
ANY= 0, /* Total */
READ= 1, /* Only reads */
WRITE= 2 /* Only writes */
};
#define QUERY_TYPES (QUERY_TYPE::WRITE+1)
typedef class Item COND;
#ifdef HAVE_RESPONSE_TIME_DISTRIBUTION
extern void query_response_time_init ();
extern void query_response_time_free ();
extern int query_response_time_flush ();
extern void query_response_time_collect(ulonglong query_time);
extern int query_response_time_fill (THD* thd, TABLE_LIST *tables, COND *cond);
extern void query_response_time_init();
extern void query_response_time_free();
extern int query_response_time_flush_all();
extern int query_response_time_flush_read();
extern int query_response_time_flush_write();
extern void query_response_time_collect(QUERY_TYPE type, ulonglong query_time);
extern int query_response_time_fill(THD* thd, TABLE_LIST *tables,
COND *cond);
extern int query_response_time_fill_read(THD* thd, TABLE_LIST *tables,
COND *cond);
extern int query_response_time_fill_write(THD* thd, TABLE_LIST *tables,
COND *cond);
extern int query_response_time_fill_read_write(THD* thd, TABLE_LIST *tables,
COND *cond);
extern ulong opt_query_response_time_range_base;
extern my_bool opt_query_response_time_stats;

4
sql/handler.cc
View file

@ -5269,7 +5269,8 @@ int handler::ha_check(THD *thd, HA_CHECK_OPT *check_opt)
void handler::mark_trx_read_write_internal()
{
Ha_trx_info *ha_info= &ha_thd()->ha_data[ht->slot].ha_info[0];
THD *thd= ha_thd();
Ha_trx_info *ha_info= &thd->ha_data[ht->slot].ha_info[0];
/*
When a storage engine method is called, the transaction must
have been started, unless it's a DDL call, for which the
@ -5287,6 +5288,7 @@ void handler::mark_trx_read_write_internal()
if (table_share == NULL || table_share->tmp_table == NO_TMP_TABLE)
ha_info->set_trx_read_write();
}
thd->stmt_changes_data= 1;
}

7
sql/log.cc
View file

@ -1334,11 +1334,9 @@ bool LOGGER::general_log_write(THD *thd, enum enum_server_command command,
char user_host_buff[MAX_USER_HOST_SIZE + 1];
uint user_host_len= 0;
my_hrtime_t current_time;
DBUG_ASSERT(thd);
user_host_len= make_user_name(thd, user_host_buff);
current_time= my_hrtime();
mysql_audit_general_log(thd, hrtime_to_time(current_time),
@ -7391,7 +7389,7 @@ bool LOGGER::log_command(THD *thd, enum enum_server_command command)
{
/*
Log command if we have at least one log event handler enabled and want
to log this king of commands
to log this kind of commands
*/
if (!(*general_log_handler_list && (what_to_log & (1L << (uint) command))))
return FALSE;
@ -7426,7 +7424,8 @@ bool general_log_write(THD *thd, enum enum_server_command command,
const char *query, size_t query_length)
{
/* Write the message to the log if we want to log this king of commands */
if (logger.log_command(thd, command) || mysql_audit_general_enabled())
if ((opt_log && logger.log_command(thd, command)) ||
mysql_audit_general_enabled())
return logger.general_log_write(thd, command, query, query_length);
return FALSE;

3
sql/sp_instr.cc
View file

@ -864,7 +864,8 @@ sp_instr_stmt::execute(THD *thd, uint *nextp)
bool log_slow= !res && thd->enable_slow_log;
/* Finalize server status flags after executing a statement. */
if (log_slow || thd->get_stmt_da()->is_eof())
if (log_slow || thd->get_stmt_da()->is_eof() ||
mysql_audit_general_enabled())
thd->update_server_status();
if (thd->get_stmt_da()->is_eof())

5
sql/sql_base.cc
View file

@ -1905,6 +1905,7 @@ bool open_table(THD *thd, TABLE_LIST *table_list, Open_table_context *ot_ctx)
TABLE_SHARE *share;
uint gts_flags;
bool from_share= false;
bool is_write_lock_request= table_list->mdl_request.is_write_lock_request();
#ifdef WITH_PARTITION_STORAGE_ENGINE
int part_names_error=0;
#endif
@ -1934,7 +1935,7 @@ bool open_table(THD *thd, TABLE_LIST *table_list, Open_table_context *ot_ctx)
Note that we allow write locks on log tables as otherwise logging
to general/slow log would be disabled in read only transactions.
*/
if (table_list->mdl_request.is_write_lock_request() &&
if (is_write_lock_request &&
thd->tx_read_only &&
!(flags & (MYSQL_LOCK_LOG_TABLE | MYSQL_OPEN_HAS_MDL_LOCK)))
{
@ -2316,7 +2317,7 @@ retry_share:
else if (table->s->online_backup)
mdl_type= MDL_BACKUP_TRANS_DML;
if (table_list->mdl_request.is_write_lock_request() &&
if (is_write_lock_request &&
! (flags & (MYSQL_OPEN_IGNORE_GLOBAL_READ_LOCK |
MYSQL_OPEN_FORCE_SHARED_MDL |
MYSQL_OPEN_FORCE_SHARED_HIGH_PRIO_MDL |

10
sql/sql_class.cc
View file

@ -5920,6 +5920,7 @@ void THD::reset_sub_statement_state(Sub_statement_state *backup,
first_successful_insert_id_in_prev_stmt;
backup->first_successful_insert_id_in_cur_stmt=
first_successful_insert_id_in_cur_stmt;
backup->do_union= binlog_evt_union.do_union;
store_slow_query_state(backup);
if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) &&
@ -6001,9 +6002,11 @@ void THD::restore_sub_statement_state(Sub_statement_state *backup)
if (!in_sub_stmt)
is_fatal_sub_stmt_error= false;
if ((variables.option_bits & OPTION_BIN_LOG) && is_update_query(lex->sql_command) &&
!is_current_stmt_binlog_format_row())
if (binlog_evt_union.do_union != backup->do_union)
{
DBUG_ASSERT(!backup->do_union);
mysql_bin_log.stop_union_events(this);
}
/*
The following is added to the old values as we are interested in the
@ -6031,6 +6034,7 @@ void THD::store_slow_query_state(Sub_statement_state *backup)
backup->tmp_tables_size= tmp_tables_size;
backup->tmp_tables_used= tmp_tables_used;
backup->handler_stats= handler_stats;
backup->stmt_changes_data= stmt_changes_data;
}
/* Reset variables related to slow query log */
@ -6059,6 +6063,7 @@ void THD::reset_slow_query_state(Sub_statement_state *backup)
}
if ((variables.log_slow_verbosity & LOG_SLOW_VERBOSITY_ENGINE))
handler_stats.reset();
stmt_changes_data= 0; // Can be used by audit plugins
}
/*
@ -6090,6 +6095,7 @@ void THD::add_slow_query_state(Sub_statement_state *backup)
}
if ((variables.log_slow_verbosity & LOG_SLOW_VERBOSITY_ENGINE))
handler_stats.add(&backup->handler_stats);
stmt_changes_data|= backup->stmt_changes_data;
}

3
sql/sql_class.h
View file

@ -2120,6 +2120,8 @@ public:
bool enable_slow_log;
bool last_insert_id_used;
bool in_stored_procedure;
bool do_union;
bool stmt_changes_data;
enum enum_check_fields count_cuted_fields;
};
@ -3860,6 +3862,7 @@ public:
See comment above regarding transaction_isolation.
*/
bool tx_read_only;
bool stmt_changes_data;
enum_check_fields count_cuted_fields;
DYNAMIC_ARRAY user_var_events; /* For user variables replication */

6
sql/sql_parse.cc
View file

@ -3511,10 +3511,12 @@ mysql_execute_command(THD *thd, bool is_called_from_prepared_stmt)
table_list.first);
/*
Remember last commmand executed, so that we can use it in functions called by
dispatch_command()
Remember last commmand executed, so that we can use it in places
like mysql_audit_plugin.
*/
thd->last_sql_command= lex->sql_command;
thd->stmt_changes_data|= (sql_command_flags[lex->sql_command] &
CF_CHANGES_DATA);
/*
Reset warning count for each query that uses tables

8
sql/sql_select.cc
View file

@ -22873,7 +22873,13 @@ free_tmp_table(THD *thd, TABLE *entry)
thd->tmp_tables_size+= (entry->file->stats.data_file_length +
entry->file->stats.index_file_length);
}
entry->file->ha_drop_table(entry->s->path.str);
/*
This is an internal temporary table, we should not call ha_drop_table()
as it will mark the transaction read/write
*/
DBUG_ASSERT(entry->s->tmp_table == SYSTEM_TMP_TABLE ||
entry->s->tmp_table == INTERNAL_TMP_TABLE);
entry->file->drop_table(entry->s->path.str);
delete entry->file;
entry->file= NULL;
entry->reset_created();