1########### suite/sysschema/t/pr_statement_performance_analyzer.test #############
2#                                                                                #
3# Testing of of the sys.statement_performance_analyzer() procedure               #
4#                                                                                #
5# Creation:                                                                      #
6# 2015-07-28 jkrogh Implement this test as part of                               #
7#                   WL#7804 REPORT FOR SUPPORT                                   #
8#                                                                                #
9##################################################################################
10
11-- source include/not_embedded.inc
12# Performance schema tracks prepared statements separately, and does not
13# yet have a summary view that we can use for this view.
14# Until then, we disable this test with --ps-protocol
15-- source include/no_protocol.inc
16# Bug #23290879 - For reasons unknown to man this test fails randomly only on Windows
17-- source include/not_windows.inc
18
19use test;
20--disable_warnings
21DROP TABLE IF EXISTS t1;
22DROP TEMPORARY TABLE IF EXISTS tmp_digests_ini;
23DROP VIEW IF EXISTS view_digests;
24--enable_warnings
25
26# Create a table
27CREATE TABLE t1 (id INT PRIMARY KEY, val int);
28
29# Create a new connection to make the actual changes
30# Create the connection now to ensure queries like "SELECT @@`version_comment` LIMIT 1" are excluded
31connect (con1,localhost,root,,);
32connection con1;
33use test;
34--let $con1_thread_id= `SELECT THREAD_ID FROM performance_schema.threads WHERE PROCESSLIST_ID = CONNECTION_ID()`
35
36# Disable instrumentation for all other threads other than the one that will
37# my monitored for this test ($con1_thread_id)
38connection default;
39--disable_result_log
40--replace_result $con1_thread_id CON1_THREAD_ID
41eval UPDATE performance_schema.threads SET INSTRUMENTED = IF(THREAD_ID = $con1_thread_id, 'YES', 'NO');
42CALL sys.ps_setup_enable_consumer('events_statements_history_long');
43CALL sys.ps_truncate_all_tables(FALSE);
44--enable_result_log
45
46# Start with some initial queries
47# Don't rely on the digests being constant across MySQL releases and versions, so find the
48# digest for each of the three queries by getting the last event from performance_schema.events_statements_current
49# for the con1 connection.
50connection con1;
51INSERT INTO t1 VALUES (1, 0);
52connection default;
53--let $wait_condition= SELECT SUBSTRING(SQL_TEXT, 1, 7) = 'INSERT ' FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id AND DIGEST IS NOT NULL
54--source include/wait_condition.inc
55--let $digest_insert= `SELECT DIGEST FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id ORDER BY EVENT_ID DESC LIMIT 1`
56--let $query_insert= `SELECT sys.format_statement(DIGEST_TEXT) FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id ORDER BY EVENT_ID DESC LIMIT 1`
57connection con1;
58UPDATE t1 SET val = 1 WHERE id = 1;
59connection default;
60--let $wait_condition= SELECT SUBSTRING(SQL_TEXT, 1, 7) = 'UPDATE ' FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id AND DIGEST IS NOT NULL
61--source include/wait_condition.inc
62--let $digest_update= `SELECT DIGEST FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id ORDER BY EVENT_ID DESC LIMIT 1`
63--let $query_update= `SELECT sys.format_statement(DIGEST_TEXT) FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id ORDER BY EVENT_ID DESC LIMIT 1`
64connection con1;
65SELECT t1a.* FROM t1 AS t1a LEFT OUTER JOIN (SELECT * FROM t1 AS t1b1 INNER JOIN t1 AS t1b2 USING (id, val)) AS t1b ON t1b.id > t1a.id ORDER BY t1a.val, t1a.id;
66connection default;
67--let $wait_condition= SELECT SUBSTRING(SQL_TEXT, 1, 7) = 'SELECT ' FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id AND DIGEST IS NOT NULL
68--source include/wait_condition.inc
69--let $digest_select= `SELECT DIGEST FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id ORDER BY EVENT_ID DESC LIMIT 1`
70--let $query_select= `SELECT sys.format_statement(DIGEST_TEXT) FROM performance_schema.events_statements_current WHERE THREAD_ID = $con1_thread_id ORDER BY EVENT_ID DESC LIMIT 1`
71
72# Enable to debug if some digests are not found
73# --output /tmp/digest
74# --eval SELECT '$digest_insert' AS DigestInsert, '$digest_update' AS DigestUpdate, '$digest_select' AS DigestSelect
75# --output /tmp/digest_text
76# --eval SELECT '$query_insert' AS DigestInsert, '$query_update' AS DigestUpdate, '$query_select' AS DigestSelect
77# --output /tmp/ps_history
78# SELECT THREAD_ID, EVENT_ID, END_EVENT_ID, DIGEST, SQL_TEXT FROM performance_schema.events_statements_history_long ORDER BY EVENT_ID;
79
80# Start collecting data
81CALL sys.statement_performance_analyzer('create_tmp', 'test.tmp_digests_ini', NULL);
82CALL sys.statement_performance_analyzer('snapshot', NULL, NULL);
83CALL sys.statement_performance_analyzer('save', 'test.tmp_digests_ini', NULL);
84
85# Make sure the last_seen times will be different from the SELECT statement's first_seen.
86DO SLEEP(1.2);
87
88# Make some more changes
89connection con1;
90INSERT INTO t1 VALUES (2, 0);
91UPDATE t1 SET val = 1 WHERE id = 2;
92SELECT t1a.* FROM t1 AS t1a LEFT OUTER JOIN (SELECT * FROM t1 AS t1b1 INNER JOIN t1 AS t1b2 USING (id, val)) AS t1b ON t1b.id > t1a.id ORDER BY t1a.val, t1a.id;
93disconnect con1;
94
95# Make the second collection of data and create the output
96connection default;
97# Make sure all of the queries executing in con1 has been recorded in performance_schema.events_statements_summary_by_digest
98# before continuing with the actual tests of pr_statement_performance_analyzer()
99--let $wait_condition= SELECT COUNT_STAR = 2 FROM performance_schema.events_statements_summary_by_digest WHERE DIGEST = '$digest_select'
100--source include/wait_condition.inc
101
102# Get all values to be used in replacements now to minimize the risk of the
103# values disappearing out of the performance_schema tables
104--let $o_upd_total_latency= `SELECT total_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_update'`
105--let $o_upd_max_latency= `SELECT max_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_update'`
106--let $o_upd_avg_latency= `SELECT avg_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_update'`
107--let $o_upd_first_seen= `SELECT first_seen FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_update'`
108--let $o_upd_last_seen= `SELECT last_seen FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_update'`
109--let $o_sel_total_latency= `SELECT total_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_select'`
110--let $o_sel_max_latency= `SELECT max_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_select'`
111--let $o_sel_avg_latency= `SELECT avg_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_select'`
112--let $o_sel_first_seen= `SELECT first_seen FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_select'`
113--let $o_sel_last_seen= `SELECT last_seen FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_select'`
114--let $o_ins_total_latency= `SELECT total_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_insert'`
115--let $o_ins_max_latency= `SELECT max_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_insert'`
116--let $o_ins_avg_latency= `SELECT avg_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_insert'`
117--let $o_ins_first_seen= `SELECT first_seen FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_insert'`
118--let $o_ins_last_seen= `SELECT last_seen FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_insert'`
119--let $o_upd_lock_latency= `SELECT lock_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_update'`
120--let $o_sel_lock_latency= `SELECT lock_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_select'`
121--let $o_ins_lock_latency= `SELECT lock_latency FROM sys.statement_analysis WHERE db = 'test' AND digest = '$digest_insert'`
122--let $d_upd_total_latency= `SELECT sys.format_time(TIMER_WAIT) FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA = 'test' AND DIGEST = '$digest_update' ORDER BY EVENT_ID DESC LIMIT 1`
123--let $d_sel_total_latency= `SELECT sys.format_time(TIMER_WAIT) FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA = 'test' AND DIGEST = '$digest_select' ORDER BY EVENT_ID DESC LIMIT 1`
124--let $d_ins_total_latency= `SELECT sys.format_time(TIMER_WAIT) FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA = 'test' AND DIGEST = '$digest_insert' ORDER BY EVENT_ID DESC LIMIT 1`
125--let $d_upd_tock_latency= `SELECT sys.format_time(LOCK_TIME) FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA = 'test' AND DIGEST = '$digest_update' ORDER BY EVENT_ID DESC LIMIT 1`
126--let $d_sel_tock_latency= `SELECT sys.format_time(LOCK_TIME) FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA = 'test' AND DIGEST = '$digest_select' ORDER BY EVENT_ID DESC LIMIT 1`
127--let $d_ins_tock_latency= `SELECT sys.format_time(LOCK_TIME) FROM performance_schema.events_statements_history_long WHERE CURRENT_SCHEMA = 'test' AND DIGEST = '$digest_insert' ORDER BY EVENT_ID DESC LIMIT 1`
128
129CALL sys.statement_performance_analyzer('snapshot', NULL, NULL);
130
131# Do a sanity check to ensure we are assuming the queries has the digests they have and that there is nothing else in the events_statements_summary_by_digest than there actually is.
132--replace_result $digest_insert DIGEST_INSERT $digest_update DIGEST_UPDATE $digest_select DIGEST_SELECT
133--sorted_result
134SELECT DIGEST, COUNT_STAR FROM performance_schema.events_statements_summary_by_digest;
135
136# with_runtimes_in_95th_percentile
137# It is unknown what the result will be since the execution times for each query are unknown
138# So just check that no warning or error occurs
139--disable_result_log
140CALL sys.statement_performance_analyzer('overall', NULL, 'with_runtimes_in_95th_percentile');
141CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_runtimes_in_95th_percentile');
142--enable_result_log
143
144# analysis - as there's no control of the various latencies, it may be the same for two or more of the queries.
145# So replace_result cannot be used to give it a unique value. Instead just use LATENCY for all rows.
146--replace_result $query_insert QUERY_INSERT $query_select QUERY_SELECT $query_update QUERY_UPDATE $digest_insert DIGEST_INSERT $digest_update DIGEST_UPDATE $digest_select DIGEST_SELECT $o_upd_total_latency LATENCY $o_upd_max_latency LATENCY $o_upd_avg_latency LATENCY $o_upd_lock_latency LATENCY $o_upd_first_seen FIRST_SEEN $o_upd_last_seen LAST_SEEN $o_sel_total_latency LATENCY $o_sel_max_latency LATENCY $o_sel_avg_latency LATENCY $o_sel_lock_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN $o_ins_total_latency LATENCY $o_ins_max_latency LATENCY $o_ins_avg_latency LATENCY $o_ins_lock_latency LATENCY $o_ins_first_seen FIRST_SEEN $o_ins_last_seen LAST_SEEN
147--sorted_result
148CALL sys.statement_performance_analyzer('overall', NULL, 'analysis');
149
150--replace_result $query_insert QUERY_INSERT $query_select QUERY_SELECT $query_update QUERY_UPDATE $digest_insert DIGEST_INSERT $digest_update DIGEST_UPDATE $digest_select DIGEST_SELECT $d_upd_total_latency LATENCY $o_upd_max_latency LATENCY $o_upd_first_seen FIRST_SEEN $o_upd_last_seen LAST_SEEN $d_upd_tock_latency LATENCY $d_sel_total_latency LATENCY $o_sel_max_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN $d_sel_tock_latency LATENCY $d_ins_total_latency LATENCY $o_ins_max_latency LATENCY $o_ins_first_seen FIRST_SEEN $o_ins_last_seen LAST_SEEN $d_ins_tock_latency LATENCY
151--sorted_result
152CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'analysis');
153
154# Should give an empty result except for the banner generated by the procedure
155CALL sys.statement_performance_analyzer('overall', NULL, 'with_errors_or_warnings');
156CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_errors_or_warnings');
157
158--replace_result $query_select QUERY_SELECT $digest_select DIGEST_SELECT $o_sel_total_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN
159CALL sys.statement_performance_analyzer('overall', NULL, 'with_full_table_scans');
160--replace_result $query_select QUERY_SELECT $digest_select DIGEST_SELECT $d_sel_total_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN
161CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_full_table_scans');
162
163--replace_result $query_select QUERY_SELECT $digest_select DIGEST_SELECT $o_sel_total_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN
164CALL sys.statement_performance_analyzer('overall', NULL, 'with_sorting');
165--replace_result $query_select QUERY_SELECT $digest_select DIGEST_SELECT $d_sel_total_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN
166CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_sorting');
167
168--replace_result $query_select QUERY_SELECT $digest_select DIGEST_SELECT $o_sel_total_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN
169CALL sys.statement_performance_analyzer('overall', NULL, 'with_temp_tables');
170--replace_result $query_select QUERY_SELECT $digest_select DIGEST_SELECT $d_sel_total_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN
171CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_temp_tables');
172
173# Try a custom view
174# Sort by the query, then we know the order will be INSERT, SELECT, UPDATE
175CREATE VIEW test.view_digests AS
176SELECT sys.format_statement(DIGEST_TEXT) AS query,
177       SCHEMA_NAME AS db,
178       COUNT_STAR AS exec_count,
179       sys.format_time(SUM_TIMER_WAIT) AS total_latency,
180       sys.format_time(AVG_TIMER_WAIT) AS avg_latency,
181       ROUND(IFNULL(SUM_ROWS_SENT / NULLIF(COUNT_STAR, 0), 0)) AS rows_sent_avg,
182       ROUND(IFNULL(SUM_ROWS_EXAMINED / NULLIF(COUNT_STAR, 0), 0)) AS rows_examined_avg,
183       ROUND(IFNULL(SUM_ROWS_AFFECTED / NULLIF(COUNT_STAR, 0), 0)) AS rows_affected_avg,
184       DIGEST AS digest
185  FROM performance_schema.events_statements_summary_by_digest
186 ORDER BY SUBSTRING(query, 1, 6);
187SET @sys.statement_performance_analyzer.view = 'test.view_digests';
188--replace_result $query_insert QUERY_INSERT $query_select QUERY_SELECT $query_update QUERY_UPDATE $digest_insert DIGEST_INSERT $digest_update DIGEST_UPDATE $digest_select DIGEST_SELECT $o_upd_total_latency LATENCY $o_upd_avg_latency LATENCY $o_sel_total_latency LATENCY $o_sel_avg_latency LATENCY $o_ins_total_latency LATENCY $o_ins_avg_latency LATENCY
189CALL sys.statement_performance_analyzer('overall', NULL, 'custom');
190--replace_result $query_insert QUERY_INSERT $query_select QUERY_SELECT $query_update QUERY_UPDATE $digest_insert DIGEST_INSERT $digest_update DIGEST_UPDATE $digest_select DIGEST_SELECT $d_upd_total_latency LATENCY $d_sel_total_latency LATENCY $d_ins_total_latency LATENCY
191CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'custom');
192
193# Verify that setting a limit works
194SET @sys.statement_performance_analyzer.limit = 2;
195--replace_result $query_insert QUERY_INSERT $query_select QUERY_SELECT $digest_insert DIGEST_INSERT $digest_select DIGEST_SELECT $o_ins_total_latency LATENCY $o_ins_avg_latency LATENCY $o_sel_total_latency LATENCY $o_sel_avg_latency LATENCY
196CALL sys.statement_performance_analyzer('overall', NULL, 'custom');
197
198# Test for error conditions - some of the errors depend on the sql_mode so set it explicitly
199# Which sql_modes are deprecated depends on the release, so disable warnings while setting the sql_mode
200
201
202# Use non-strict sql_mode - keep NO_AUTO_CREATE_USER as this sql_mode will be mandatory in the future:
203SET SESSION sql_mode = 'NO_AUTO_CREATE_USER';
204# Ask for a non-supported action - since strict more is not used, this will give the error: ERROR 1644 (45000): Unknown action: ''
205# Note: the action passed to the procedure is actually lost because it's truncated.
206--error ER_SIGNAL_EXCEPTION
207CALL sys.statement_performance_analyzer('do magic', NULL, NULL);
208
209
210# Use 5.7.9+ default:
211--disable_warnings
212SET SESSION sql_mode = 'ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION';
213--enable_warnings
214# Ask for a non-supported action - since strict mode is used, this will give the error: ERROR 1265 (01000): Data truncated for column 'in_action' at row 1
215--error 1265
216CALL sys.statement_performance_analyzer('do magic', NULL, NULL);
217# Try to create reserved table name
218-- error S45000
219CALL sys.statement_performance_analyzer('create_tmp', 'sys.tmp_digests', NULL);
220-- error S45000
221CALL sys.statement_performance_analyzer('create_tmp', 'sys.tmp_digests_delta', NULL);
222-- error S45000
223CALL sys.statement_performance_analyzer('create_tmp', 'tmp_digests', NULL);
224# This should succeed
225CALL sys.statement_performance_analyzer('create_tmp', 'test.tmp_digests', NULL);
226CREATE TABLE test.tmp_unsupported LIKE test.tmp_digests_ini;
227# Try to create a temporary table that already exists
228-- error S45000
229CALL sys.statement_performance_analyzer('create_tmp', 'test.tmp_digests_ini', NULL);
230# Try to create a base table that already exists
231-- error S45000
232CALL sys.statement_performance_analyzer('create_table', 'test.tmp_digests_ini', NULL);
233-- error S45000
234CALL sys.statement_performance_analyzer('create_table', 'test.tmp_unsupported', NULL);
235# Verify that the sanity check for the input table e.g. for saving snapshots works
236ALTER TABLE test.tmp_unsupported ADD COLUMN myvar int DEFAULT 0;
237-- error S45000
238CALL sys.statement_performance_analyzer('save', 'test.tmp_unsupported', NULL);
239# Try to create a snapshot or overall output with the wrong in_table
240-- error S45000
241CALL sys.statement_performance_analyzer('snapshot', 'test.new_table', NULL);
242-- error S45000
243CALL sys.statement_performance_analyzer('overall', 'test.new_table', 'analysis');
244# Try to create a delta output or save a snapshot specifying a non-existing table.
245-- error S45000
246CALL sys.statement_performance_analyzer('delta', 'test.new_table', 'analysis');
247-- error S45000
248CALL sys.statement_performance_analyzer('save', 'test.new_table', NULL);
249# Verify custom views doesn't work without the user variable set
250SET @sys.statement_performance_analyzer.view = NULL;
251DELETE FROM sys.sys_config WHERE variable = 'statement_performance_analyzer.view';
252-- error S45000
253CALL sys.statement_performance_analyzer('overall', NULL, 'custom');
254# Set the custom view to a regular table - should not work
255SET @sys.statement_performance_analyzer.view = 'test.tmp_unsupported';
256-- error S45000
257CALL sys.statement_performance_analyzer('overall', NULL, 'custom');
258
259
260# Remove the temporary tables created by the procedure
261# First ensure the tables actually exists (to avoid passing the test if the table names are changed)
262CALL sys.table_exists('sys', 'tmp_digests', @exists);
263SELECT @exists;
264CALL sys.table_exists('sys', 'tmp_digests_delta', @exists);
265SELECT @exists;
266CALL sys.statement_performance_analyzer('cleanup', NULL, NULL);
267# Verify the internal tables really were removed
268-- error ER_BAD_TABLE_ERROR
269DROP TEMPORARY TABLE sys.tmp_digests;
270-- error ER_BAD_TABLE_ERROR
271DROP TEMPORARY TABLE sys.tmp_digests_delta;
272
273# An attempt to create a delta view should fail now as there's no longer an existing snapshot.
274-- error S45000
275CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'analysis');
276# Ensure no delta table was created.
277-- error ER_BAD_TABLE_ERROR
278DROP TEMPORARY TABLE sys.tmp_digests_delta;
279
280# Try and use a table.db name > 129
281SET @identifier := REPEAT('a', 65);
282-- error 1406
283CALL sys.statement_performance_analyzer('snapshot', CONCAT(@identifier, '.', @identifier), NULL);
284
285# Clean up
286DROP TEMPORARY TABLE test.tmp_digests_ini;
287DROP TEMPORARY TABLE test.tmp_digests;
288DROP TABLE test.tmp_unsupported;
289DROP TABLE test.t1;
290DROP VIEW view_digests;
291SET @identifier := NULL;
292
293SET SESSION sql_mode = @@global.sql_mode;
294SET @sys.statement_performance_analyzer.limit = NULL;
295SET @sys.statement_performance_analyzer.view = NULL;
296--source ../include/ps_setup_consumers_cleanup.inc
297--source ../include/ps_threads_cleanup.inc
298--source ../include/sys_config_cleanup.inc
299