1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324
|
-- Copyright (c) 2014, 2016, Oracle and/or its affiliates. All rights reserved.
--
-- 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
-- the Free Software Foundation; version 2 of the License.
--
-- This program is distributed in the hope that it will be useful,
-- but WITHOUT ANY WARRANTY; without even the implied warranty of
-- MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
-- GNU General Public License for more details.
--
-- You should have received a copy of the GNU General Public License
-- along with this program; if not, write to the Free Software
-- Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
DROP PROCEDURE IF EXISTS ps_trace_statement_digest;
DELIMITER $$
CREATE DEFINER='mariadb.sys'@'localhost' PROCEDURE ps_trace_statement_digest (
IN in_digest VARCHAR(32),
IN in_runtime INT,
IN in_interval DECIMAL(2,2),
IN in_start_fresh BOOLEAN,
IN in_auto_enable BOOLEAN
)
COMMENT '
Description
-----------
Traces all instrumentation within Performance Schema for a specific
Statement Digest.
When finding a statement of interest within the
performance_schema.events_statements_summary_by_digest table, feed
the DIGEST MD5 value in to this procedure, set how long to poll for,
and at what interval to poll, and it will generate a report of all
statistics tracked within Performance Schema for that digest for the
interval.
It will also attempt to generate an EXPLAIN for the longest running
example of the digest during the interval. Note this may fail, as:
* Performance Schema truncates long SQL_TEXT values (and hence the
EXPLAIN will fail due to parse errors)
* the default schema is sys (so tables that are not fully qualified
in the query may not be found)
* some queries such as SHOW are not supported in EXPLAIN.
When the EXPLAIN fails, the error will be ignored and no EXPLAIN
output generated.
Requires the SUPER privilege for "SET sql_log_bin = 0;".
Parameters
-----------
in_digest (VARCHAR(32)):
The statement digest identifier you would like to analyze
in_runtime (INT):
The number of seconds to run analysis for
in_interval (DECIMAL(2,2)):
The interval (in seconds, may be fractional) at which to try
and take snapshots
in_start_fresh (BOOLEAN):
Whether to TRUNCATE the events_statements_history_long and
events_stages_history_long tables before starting
in_auto_enable (BOOLEAN):
Whether to automatically turn on required consumers
Example
-----------
mysql> call ps_trace_statement_digest(\'891ec6860f98ba46d89dd20b0c03652c\', 10, 0.1, true, true);
+--------------------+
| SUMMARY STATISTICS |
+--------------------+
| SUMMARY STATISTICS |
+--------------------+
1 row in set (9.11 sec)
+------------+-----------+-----------+-----------+---------------+------------+------------+
| executions | exec_time | lock_time | rows_sent | rows_examined | tmp_tables | full_scans |
+------------+-----------+-----------+-----------+---------------+------------+------------+
| 21 | 4.11 ms | 2.00 ms | 0 | 21 | 0 | 0 |
+------------+-----------+-----------+-----------+---------------+------------+------------+
1 row in set (9.11 sec)
+------------------------------------------+-------+-----------+
| event_name | count | latency |
+------------------------------------------+-------+-----------+
| stage/sql/checking query cache for query | 16 | 724.37 us |
| stage/sql/statistics | 16 | 546.92 us |
| stage/sql/freeing items | 18 | 520.11 us |
| stage/sql/init | 51 | 466.80 us |
...
| stage/sql/cleaning up | 18 | 11.92 us |
| stage/sql/executing | 16 | 6.95 us |
+------------------------------------------+-------+-----------+
17 rows in set (9.12 sec)
+---------------------------+
| LONGEST RUNNING STATEMENT |
+---------------------------+
| LONGEST RUNNING STATEMENT |
+---------------------------+
1 row in set (9.16 sec)
+-----------+-----------+-----------+-----------+---------------+------------+-----------+
| thread_id | exec_time | lock_time | rows_sent | rows_examined | tmp_tables | full_scan |
+-----------+-----------+-----------+-----------+---------------+------------+-----------+
| 166646 | 618.43 us | 1.00 ms | 0 | 1 | 0 | 0 |
+-----------+-----------+-----------+-----------+---------------+------------+-----------+
1 row in set (9.16 sec)
// Truncated for clarity...
+-----------------------------------------------------------------+
| sql_text |
+-----------------------------------------------------------------+
| select hibeventhe0_.id as id1382_, hibeventhe0_.createdTime ... |
+-----------------------------------------------------------------+
1 row in set (9.17 sec)
+------------------------------------------+-----------+
| event_name | latency |
+------------------------------------------+-----------+
| stage/sql/init | 8.61 us |
| stage/sql/Waiting for query cache lock | 453.23 us |
| stage/sql/init | 331.07 ns |
| stage/sql/checking query cache for query | 43.04 us |
...
| stage/sql/freeing items | 30.46 us |
| stage/sql/cleaning up | 662.13 ns |
+------------------------------------------+-----------+
18 rows in set (9.23 sec)
+----+-------------+--------------+-------+---------------+-----------+---------+-------------+------+-------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+--------------+-------+---------------+-----------+---------+-------------+------+-------+
| 1 | SIMPLE | hibeventhe0_ | const | fixedTime | fixedTime | 775 | const,const | 1 | NULL |
+----+-------------+--------------+-------+---------------+-----------+---------+-------------+------+-------+
1 row in set (9.27 sec)
Query OK, 0 rows affected (9.28 sec)
'
SQL SECURITY INVOKER
NOT DETERMINISTIC
MODIFIES SQL DATA
BEGIN
DECLARE v_start_fresh BOOLEAN DEFAULT false;
DECLARE v_auto_enable BOOLEAN DEFAULT false;
DECLARE v_explain BOOLEAN DEFAULT true;
DECLARE v_this_thread_enabed ENUM('YES', 'NO');
DECLARE v_runtime INT DEFAULT 0;
DECLARE v_start INT DEFAULT 0;
DECLARE v_found_stmts INT;
SET @log_bin := @@sql_log_bin;
SET sql_log_bin = 0;
-- Do not track the current thread, it will kill the stack
SELECT INSTRUMENTED INTO v_this_thread_enabed FROM performance_schema.threads WHERE PROCESSLIST_ID = CONNECTION_ID();
CALL sys.ps_setup_disable_thread(CONNECTION_ID());
DROP TEMPORARY TABLE IF EXISTS stmt_trace;
CREATE TEMPORARY TABLE stmt_trace (
thread_id BIGINT UNSIGNED,
timer_start BIGINT UNSIGNED,
event_id BIGINT UNSIGNED,
sql_text longtext,
timer_wait BIGINT UNSIGNED,
lock_time BIGINT UNSIGNED,
errors BIGINT UNSIGNED,
mysql_errno INT,
rows_sent BIGINT UNSIGNED,
rows_affected BIGINT UNSIGNED,
rows_examined BIGINT UNSIGNED,
created_tmp_tables BIGINT UNSIGNED,
created_tmp_disk_tables BIGINT UNSIGNED,
no_index_used BIGINT UNSIGNED,
PRIMARY KEY (thread_id, timer_start)
);
DROP TEMPORARY TABLE IF EXISTS stmt_stages;
CREATE TEMPORARY TABLE stmt_stages (
event_id BIGINT UNSIGNED,
stmt_id BIGINT UNSIGNED,
event_name VARCHAR(128),
timer_wait BIGINT UNSIGNED,
PRIMARY KEY (event_id)
);
SET v_start_fresh = in_start_fresh;
IF v_start_fresh THEN
TRUNCATE TABLE performance_schema.events_statements_history_long;
TRUNCATE TABLE performance_schema.events_stages_history_long;
END IF;
SET v_auto_enable = in_auto_enable;
IF v_auto_enable THEN
CALL sys.ps_setup_save(0);
UPDATE performance_schema.threads
SET INSTRUMENTED = IF(PROCESSLIST_ID IS NOT NULL, 'YES', 'NO');
-- Only the events_statements_history_long and events_stages_history_long tables and their ancestors are needed
UPDATE performance_schema.setup_consumers
SET ENABLED = 'YES'
WHERE NAME NOT LIKE '%\_history'
AND NAME NOT LIKE 'events_wait%'
AND NAME NOT LIKE 'events_transactions%'
AND NAME <> 'statements_digest';
UPDATE performance_schema.setup_instruments
SET ENABLED = 'YES',
TIMED = 'YES'
WHERE NAME LIKE 'statement/%' OR NAME LIKE 'stage/%';
END IF;
WHILE v_runtime < in_runtime DO
SELECT UNIX_TIMESTAMP() INTO v_start;
INSERT IGNORE INTO stmt_trace
SELECT thread_id, timer_start, event_id, sql_text, timer_wait, lock_time, errors, mysql_errno,
rows_sent, rows_affected, rows_examined, created_tmp_tables, created_tmp_disk_tables, no_index_used
FROM performance_schema.events_statements_history_long
WHERE digest = in_digest;
INSERT IGNORE INTO stmt_stages
SELECT stages.event_id, stmt_trace.event_id,
stages.event_name, stages.timer_wait
FROM performance_schema.events_stages_history_long AS stages
JOIN stmt_trace ON stages.nesting_event_id = stmt_trace.event_id;
SELECT SLEEP(in_interval) INTO @sleep;
SET v_runtime = v_runtime + (UNIX_TIMESTAMP() - v_start);
END WHILE;
SELECT "SUMMARY STATISTICS";
SELECT COUNT(*) executions,
format_pico_time(SUM(timer_wait)) AS exec_time,
format_pico_time(SUM(lock_time)) AS lock_time,
SUM(rows_sent) AS rows_sent,
SUM(rows_affected) AS rows_affected,
SUM(rows_examined) AS rows_examined,
SUM(created_tmp_tables) AS tmp_tables,
SUM(no_index_used) AS full_scans
FROM stmt_trace;
SELECT event_name,
COUNT(*) as count,
format_pico_time(SUM(timer_wait)) as latency
FROM stmt_stages
GROUP BY event_name
ORDER BY SUM(timer_wait) DESC;
SELECT "LONGEST RUNNING STATEMENT";
SELECT thread_id,
format_pico_time(timer_wait) AS exec_time,
format_pico_time(lock_time) AS lock_time,
rows_sent,
rows_affected,
rows_examined,
created_tmp_tables AS tmp_tables,
no_index_used AS full_scan
FROM stmt_trace
ORDER BY timer_wait DESC LIMIT 1;
SELECT sql_text
FROM stmt_trace
ORDER BY timer_wait DESC LIMIT 1;
SELECT sql_text, event_id INTO @sql, @sql_id
FROM stmt_trace
ORDER BY timer_wait DESC LIMIT 1;
IF (@sql_id IS NOT NULL) THEN
SELECT event_name,
format_pico_time(timer_wait) as latency
FROM stmt_stages
WHERE stmt_id = @sql_id
ORDER BY event_id;
END IF;
DROP TEMPORARY TABLE stmt_trace;
DROP TEMPORARY TABLE stmt_stages;
IF (@sql IS NOT NULL) THEN
SET @stmt := CONCAT("EXPLAIN FORMAT=JSON ", @sql);
BEGIN
-- Not all queries support EXPLAIN, so catch the cases that are
-- not supported. Currently that includes cases where the table
-- is not fully qualified and is not in the default schema for this
-- procedure as it's not possible to change the default schema inside
-- a procedure.
--
-- Errno = 1064: You have an error in your SQL syntax
-- Errno = 1146: Table '...' doesn't exist
DECLARE CONTINUE HANDLER FOR 1064, 1146 SET v_explain = false;
PREPARE explain_stmt FROM @stmt;
END;
IF (v_explain) THEN
EXECUTE explain_stmt;
DEALLOCATE PREPARE explain_stmt;
END IF;
END IF;
IF v_auto_enable THEN
CALL sys.ps_setup_reload_saved();
END IF;
-- Restore INSTRUMENTED for this thread
IF (v_this_thread_enabed = 'YES') THEN
CALL sys.ps_setup_enable_thread(CONNECTION_ID());
END IF;
SET sql_log_bin = @log_bin;
END$$
DELIMITER ;
|