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
|
-- Copyright (c) 2014, 2015, 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_thread;
DELIMITER $$
CREATE DEFINER='mariadb.sys'@'localhost' PROCEDURE ps_trace_thread (
IN in_thread_id BIGINT UNSIGNED,
IN in_outfile VARCHAR(255),
IN in_max_runtime DECIMAL(20,2),
IN in_interval DECIMAL(20,2),
IN in_start_fresh BOOLEAN,
IN in_auto_setup BOOLEAN,
IN in_debug BOOLEAN
)
COMMENT '
Description
-----------
Dumps all data within Performance Schema for an instrumented thread,
to create a DOT formatted graph file.
Each resultset returned from the procedure should be used for a complete graph
Requires the SUPER privilege for "SET sql_log_bin = 0;".
Parameters
-----------
in_thread_id (BIGINT UNSIGNED):
The thread that you would like a stack trace for
in_outfile (VARCHAR(255)):
The filename the dot file will be written to
in_max_runtime (DECIMAL(20,2)):
The maximum time to keep collecting data.
Use NULL to get the default which is 60 seconds.
in_interval (DECIMAL(20,2)):
How long to sleep between data collections.
Use NULL to get the default which is 1 second.
in_start_fresh (BOOLEAN):
Whether to reset all Performance Schema data before tracing.
in_auto_setup (BOOLEAN):
Whether to disable all other threads and enable all consumers/instruments.
This will also reset the settings at the end of the run.
in_debug (BOOLEAN):
Whether you would like to include file:lineno in the graph
Example
-----------
mysql> CALL sys.ps_trace_thread(25, CONCAT(\'/tmp/stack-\', REPLACE(NOW(), \' \', \'-\'), \'.dot\'), NULL, NULL, TRUE, TRUE, TRUE);
+-------------------+
| summary |
+-------------------+
| Disabled 1 thread |
+-------------------+
1 row in set (0.00 sec)
+---------------------------------------------+
| Info |
+---------------------------------------------+
| Data collection starting for THREAD_ID = 25 |
+---------------------------------------------+
1 row in set (0.03 sec)
+-----------------------------------------------------------+
| Info |
+-----------------------------------------------------------+
| Stack trace written to /tmp/stack-2014-02-16-21:18:41.dot |
+-----------------------------------------------------------+
1 row in set (60.07 sec)
+-------------------------------------------------------------------+
| Convert to PDF |
+-------------------------------------------------------------------+
| dot -Tpdf -o /tmp/stack_25.pdf /tmp/stack-2014-02-16-21:18:41.dot |
+-------------------------------------------------------------------+
1 row in set (60.07 sec)
+-------------------------------------------------------------------+
| Convert to PNG |
+-------------------------------------------------------------------+
| dot -Tpng -o /tmp/stack_25.png /tmp/stack-2014-02-16-21:18:41.dot |
+-------------------------------------------------------------------+
1 row in set (60.07 sec)
+------------------+
| summary |
+------------------+
| Enabled 1 thread |
+------------------+
1 row in set (60.32 sec)
'
SQL SECURITY INVOKER
NOT DETERMINISTIC
MODIFIES SQL DATA
BEGIN
DECLARE v_done bool DEFAULT FALSE;
DECLARE v_start, v_runtime DECIMAL(20,2) DEFAULT 0.0;
DECLARE v_min_event_id bigint unsigned DEFAULT 0;
DECLARE v_this_thread_enabed ENUM('YES', 'NO');
DECLARE v_event longtext;
DECLARE c_stack CURSOR FOR
SELECT CONCAT(IF(nesting_event_id IS NOT NULL, CONCAT(nesting_event_id, ' -> '), ''),
event_id, '; ', event_id, ' [label="',
-- Convert from picoseconds to microseconds
'(', format_pico_time(timer_wait), ') ',
IF (event_name NOT LIKE 'wait/io%',
SUBSTRING_INDEX(event_name, '/', -2),
IF (event_name NOT LIKE 'wait/io/file%' OR event_name NOT LIKE 'wait/io/socket%',
SUBSTRING_INDEX(event_name, '/', -4),
event_name)
),
-- Always dump the extra wait information gathered for statements
IF (event_name LIKE 'statement/%', IFNULL(CONCAT('\\n', wait_info), ''), ''),
-- If debug is enabled, add the file:lineno information for waits
IF (in_debug AND event_name LIKE 'wait%', wait_info, ''),
'", ',
-- Depending on the type of event, style appropriately
CASE WHEN event_name LIKE 'wait/io/file%' THEN
'shape=box, style=filled, color=red'
WHEN event_name LIKE 'wait/io/table%' THEN
'shape=box, style=filled, color=green'
WHEN event_name LIKE 'wait/io/socket%' THEN
'shape=box, style=filled, color=yellow'
WHEN event_name LIKE 'wait/synch/mutex%' THEN
'style=filled, color=lightskyblue'
WHEN event_name LIKE 'wait/synch/cond%' THEN
'style=filled, color=darkseagreen3'
WHEN event_name LIKE 'wait/synch/rwlock%' THEN
'style=filled, color=orchid'
WHEN event_name LIKE 'wait/lock%' THEN
'shape=box, style=filled, color=tan'
WHEN event_name LIKE 'statement/%' THEN
CONCAT('shape=box, style=bold',
-- Style statements depending on COM vs SQL
CASE WHEN event_name LIKE 'statement/com/%' THEN
' style=filled, color=darkseagreen'
ELSE
-- Use long query time from the server to
-- flag long running statements in red
IF((timer_wait/1000000000000) > @@log_slow_query_time,
' style=filled, color=red',
' style=filled, color=lightblue')
END
)
WHEN event_name LIKE 'stage/%' THEN
'style=filled, color=slategray3'
-- IDLE events are on their own, call attention to them
WHEN event_name LIKE '%idle%' THEN
'shape=box, style=filled, color=firebrick3'
ELSE '' END,
'];\n'
) event, event_id
FROM (
-- Select all statements, with the extra tracing information available
(SELECT thread_id, event_id, event_name, timer_wait, timer_start, nesting_event_id,
CONCAT(sql_text, '\\n',
'errors: ', errors, '\\n',
'warnings: ', warnings, '\\n',
'lock time: ', format_pico_time(lock_time),'\\n',
'rows affected: ', rows_affected, '\\n',
'rows sent: ', rows_sent, '\\n',
'rows examined: ', rows_examined, '\\n',
'tmp tables: ', created_tmp_tables, '\\n',
'tmp disk tables: ', created_tmp_disk_tables, '\\n'
'select scan: ', select_scan, '\\n',
'select full join: ', select_full_join, '\\n',
'select full range join: ', select_full_range_join, '\\n',
'select range: ', select_range, '\\n',
'select range check: ', select_range_check, '\\n',
'sort merge passes: ', sort_merge_passes, '\\n',
'sort rows: ', sort_rows, '\\n',
'sort range: ', sort_range, '\\n',
'sort scan: ', sort_scan, '\\n',
'no index used: ', IF(no_index_used, 'TRUE', 'FALSE'), '\\n',
'no good index used: ', IF(no_good_index_used, 'TRUE', 'FALSE'), '\\n'
) AS wait_info
FROM performance_schema.events_statements_history_long
WHERE thread_id = in_thread_id AND event_id > v_min_event_id)
UNION
-- Select all stages
(SELECT thread_id, event_id, event_name, timer_wait, timer_start, nesting_event_id, null AS wait_info
FROM performance_schema.events_stages_history_long
WHERE thread_id = in_thread_id AND event_id > v_min_event_id)
UNION
-- Select all events, adding information appropriate to the event
(SELECT thread_id, event_id,
CONCAT(event_name,
IF(event_name NOT LIKE 'wait/synch/mutex%', IFNULL(CONCAT(' - ', operation), ''), ''),
IF(number_of_bytes IS NOT NULL, CONCAT(' ', number_of_bytes, ' bytes'), ''),
IF(event_name LIKE 'wait/io/file%', '\\n', ''),
IF(object_schema IS NOT NULL, CONCAT('\\nObject: ', object_schema, '.'), ''),
IF(object_name IS NOT NULL,
IF (event_name LIKE 'wait/io/socket%',
-- Print the socket if used, else the IP:port as reported
CONCAT('\\n', IF (object_name LIKE ':0%', @@socket, object_name)),
object_name),
''
),
IF(index_name IS NOT NULL, CONCAT(' Index: ', index_name), ''), '\\n'
) AS event_name,
timer_wait, timer_start, nesting_event_id, source AS wait_info
FROM performance_schema.events_waits_history_long
WHERE thread_id = in_thread_id AND event_id > v_min_event_id)
) events
ORDER BY event_id;
DECLARE CONTINUE HANDLER FOR NOT FOUND SET v_done = TRUE;
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());
IF (in_auto_setup) THEN
CALL sys.ps_setup_save(0);
-- Ensure only the thread to create the stack trace for is instrumented and that we instrument everything.
DELETE FROM performance_schema.setup_actors;
UPDATE performance_schema.threads
SET INSTRUMENTED = IF(THREAD_ID = in_thread_id, 'YES', 'NO');
-- only the %_history_long tables and it ancestors are needed
UPDATE performance_schema.setup_consumers
SET ENABLED = 'YES'
WHERE NAME NOT LIKE '%\_history';
UPDATE performance_schema.setup_instruments
SET ENABLED = 'YES',
TIMED = 'YES';
END IF;
IF (in_start_fresh) THEN
TRUNCATE performance_schema.events_statements_history_long;
TRUNCATE performance_schema.events_stages_history_long;
TRUNCATE performance_schema.events_waits_history_long;
END IF;
DROP TEMPORARY TABLE IF EXISTS tmp_events;
CREATE TEMPORARY TABLE tmp_events (
event_id bigint unsigned NOT NULL,
event longblob,
PRIMARY KEY (event_id)
);
-- Print headers for a .dot file
INSERT INTO tmp_events VALUES (0, CONCAT('digraph events { rankdir=LR; nodesep=0.10;\n',
'// Stack created .....: ', NOW(), '\n',
'// MySQL version .....: ', VERSION(), '\n',
'// MySQL hostname ....: ', @@hostname, '\n',
'// MySQL port ........: ', @@port, '\n',
'// MySQL socket ......: ', @@socket, '\n',
'// MySQL user ........: ', CURRENT_USER(), '\n'));
SELECT CONCAT('Data collection starting for THREAD_ID = ', in_thread_id) AS 'Info';
SET v_min_event_id = 0,
v_start = UNIX_TIMESTAMP(),
in_interval = IFNULL(in_interval, 1.00),
in_max_runtime = IFNULL(in_max_runtime, 60.00);
WHILE (v_runtime < in_max_runtime
AND (SELECT INSTRUMENTED FROM performance_schema.threads WHERE THREAD_ID = in_thread_id) = 'YES') DO
SET v_done = FALSE;
OPEN c_stack;
c_stack_loop: LOOP
FETCH c_stack INTO v_event, v_min_event_id;
IF v_done THEN
LEAVE c_stack_loop;
END IF;
IF (LENGTH(v_event) > 0) THEN
INSERT INTO tmp_events VALUES (v_min_event_id, v_event);
END IF;
END LOOP;
CLOSE c_stack;
SELECT SLEEP(in_interval) INTO @sleep;
SET v_runtime = (UNIX_TIMESTAMP() - v_start);
END WHILE;
INSERT INTO tmp_events VALUES (v_min_event_id+1, '}');
SET @query = CONCAT('SELECT event FROM tmp_events ORDER BY event_id INTO OUTFILE ''', in_outfile, ''' FIELDS ESCAPED BY '''' LINES TERMINATED BY ''''');
PREPARE stmt_output FROM @query;
EXECUTE stmt_output;
DEALLOCATE PREPARE stmt_output;
SELECT CONCAT('Stack trace written to ', in_outfile) AS 'Info';
SELECT CONCAT('dot -Tpdf -o /tmp/stack_', in_thread_id, '.pdf ', in_outfile) AS 'Convert to PDF';
SELECT CONCAT('dot -Tpng -o /tmp/stack_', in_thread_id, '.png ', in_outfile) AS 'Convert to PNG';
DROP TEMPORARY TABLE tmp_events;
-- Reset the settings for the performance schema
IF (in_auto_setup) 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 ;
|
