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