· 6 years ago · Apr 30, 2019, 06:28 PM
1Analyzing Slow Query Logs:
2
3# A software update is available:
4# * The current version for Percona::Toolkit is 3.0.5
5
6
7# 760ms user time, 160ms system time, 41.62M rss, 148.00M vsz
8# Current date: Fri Apr 19 18:09:48 2019
9# Hostname: dbserver-1b434814.c.pantheon-dmz.internal
10# Files: mysqld-slow-query.log
11# Overall: 2.03k total, 25 unique, 0.00 QPS, 0.00x concurrency ___________
12# Time range: 2019-03-30 13:34:40 to 2019-04-19 13:20:41
13# Attribute total min max avg 95% stddev median
14# ============ ======= ======= ======= ======= ======= ======= =======
15# Exec time 2546s 1s 4s 1s 2s 344ms 1s
16# Lock time 149s 0 3s 73ms 705ms 228ms 36us
17# Rows sent 10.39M 0 997.35k 5.24k 0.99 48.29k 0
18# Rows examine 2.01G 0 1.15M 1.01M 1.14M 323.84k 1.14M
19# Query size 301.75k 31 12.66k 152.29 97.36 935.37 76.28
20
21# Profile
22# Rank Query ID Response time Calls R/Call V/M Item
23# ==== ================== =============== ===== ====== ===== =============
24# 1 0xD38F898E95D9BE0A 2285.6199 89.8% 1855 1.2321 0.09 DELETE elink_pantheon_sessions
25# 2 0x6859B71778D84FCB 82.1837 3.2% 56 1.4676 0.04 SELECT elink_services_by_cities
26# 3 0x67A347A2812914DF 79.4594 3.1% 48 1.6554 0.12 SELECT elink_pantheon_sessions
27# 4 0xBF241E31C2C365FB 27.0896 1.1% 20 1.3545 0.03 UPDATE elink_options
28# MISC 0xMISC 71.2474 2.8% 50 1.4249 0.0 <21 ITEMS>
29
30# Query 1: 0.00 QPS, 0.00x concurrency, ID 0xD38F898E95D9BE0A at byte 411106
31# This item is included in the report because it matches --limit.
32# Scores: V/M = 0.09
33# Time range: 2019-03-30 13:34:40 to 2019-04-19 13:20:41
34# Attribute pct total min max avg 95% stddev median
35# ============ === ======= ======= ======= ======= ======= ======= =======
36# Count 91 1855
37# Exec time 89 2286s 1s 4s 1s 2s 336ms 1s
38# Lock time 99 149s 21us 3s 80ms 740ms 237ms 36us
39# Rows sent 0 0 0 0 0 0 0 0
40# Rows examine 99 1.99G 344.26k 1.15M 1.10M 1.14M 142.80k 1.14M
41# Query size 46 139.49k 77 77 77 77 0 77
42# String:
43# Databases pantheon
44# Hosts 10.128.15.230 (488/26%), 10.128.2.60 (470/25%)... 2 more
45# Users pantheon
46# Query_time distribution
47# 1us
48# 10us
49# 100us
50# 1ms
51# 10ms
52# 100ms
53# 1s ################################################################
54# 10s+
55# Tables
56# SHOW TABLE STATUS FROM `pantheon` LIKE 'elink_pantheon_sessions'\G
57# SHOW CREATE TABLE `pantheon`.`elink_pantheon_sessions`\G
58DELETE FROM elink_pantheon_sessions WHERE `datetime` <= '2019-03-28 16:20:40'\G
59# Converted for EXPLAIN
60# EXPLAIN /*!50100 PARTITIONS*/
61select * from elink_pantheon_sessions WHERE `datetime` <= '2019-03-28 16:20:40'\G
62
63# Query 2: 0.00 QPS, 0.00x concurrency, ID 0x6859B71778D84FCB at byte 722669
64# This item is included in the report because it matches --limit.
65# Scores: V/M = 0.04
66# Time range: 2019-04-06 14:53:16 to 2019-04-19 09:20:37
67# Attribute pct total min max avg 95% stddev median
68# ============ === ======= ======= ======= ======= ======= ======= =======
69# Count 2 56
70# Exec time 3 82s 1s 2s 1s 2s 241ms 1s
71# Lock time 0 3ms 31us 152us 44us 57us 20us 38us
72# Rows sent 0 56 1 1 1 1 0 1
73# Rows examine 0 2.28M 41.74k 41.74k 41.74k 41.74k 0 41.74k
74# Query size 2 7.58k 105 337 138.68 313.99 54.60 118.34
75# String:
76# Databases pantheon
77# Hosts 10.128.2.60 (20/35%), 10.128.1.121 (14/25%)... 2 more
78# Users pantheon
79# Query_time distribution
80# 1us
81# 10us
82# 100us
83# 1ms
84# 10ms
85# 100ms
86# 1s ################################################################
87# 10s+
88# Tables
89# SHOW TABLE STATUS FROM `pantheon` LIKE 'elink_services_by_cities'\G
90# SHOW CREATE TABLE `pantheon`.`elink_services_by_cities`\G
91# EXPLAIN /*!50100 PARTITIONS*/
92SELECT COUNT(*) FROM elink_services_by_cities where type='HighSpeedInternet' and state_wo_space='' and city_wo_space=''\G
93
94# Query 3: 0.00 QPS, 0.00x concurrency, ID 0x67A347A2812914DF at byte 539176
95# This item is included in the report because it matches --limit.
96# Scores: V/M = 0.12
97# Time range: 2019-03-31 07:33:15 to 2019-04-19 07:40:04
98# Attribute pct total min max avg 95% stddev median
99# ============ === ======= ======= ======= ======= ======= ======= =======
100# Count 2 48
101# Exec time 3 79s 1s 4s 2s 2s 453ms 1s
102# Lock time 0 1ms 20us 38us 26us 33us 4us 23us
103# Rows sent 99 10.39M 2.17k 997.35k 221.65k 485.50k 230.68k 312.96k
104# Rows examine 0 10.39M 2.17k 997.35k 221.65k 485.50k 230.68k 312.96k
105# Query size 0 2.72k 52 64 58 62.76 5.56 62.76
106# String:
107# Databases pantheon
108# Hosts 35.188.101.186 (8/16%), 104.154.186.151 (4/8%)... 14 more
109# Users pantheon
110# Query_time distribution
111# 1us
112# 10us
113# 100us
114# 1ms
115# 10ms
116# 100ms
117# 1s ################################################################
118# 10s+
119# Tables
120# SHOW TABLE STATUS FROM `pantheon` LIKE 'elink_pantheon_sessions'\G
121# SHOW CREATE TABLE `pantheon`.`elink_pantheon_sessions`\G
122SELECT /*!40001 SQL_NO_CACHE */ * FROM `elink_pantheon_sessions`\G
123# Converted for EXPLAIN
124# EXPLAIN /*!50100 PARTITIONS*/
125SELECT /*!40001 SQL_NO_CACHE */ * FROM `elink_pantheon_sessions`\G
126
127# Query 4: 0.00 QPS, 0.00x concurrency, ID 0xBF241E31C2C365FB at byte 610735
128# This item is included in the report because it matches --outliers.
129# Scores: V/M = 0.03
130# Time range: 2019-04-07 18:52:46 to 2019-04-19 13:20:41
131# Attribute pct total min max avg 95% stddev median
132# ============ === ======= ======= ======= ======= ======= ======= =======
133# Count 0 20
134# Exec time 1 27s 1s 2s 1s 2s 217ms 1s
135# Lock time 0 83ms 25us 47ms 4ms 19ms 11ms 194us
136# Rows sent 0 0 0 0 0 0 0 0
137# Rows examine 0 20 1 1 1 1 0 1
138# Query size 46 140.04k 84 12.66k 7.00k 12.50k 6.18k 12.50k
139# String:
140# Databases pantheon
141# Hosts 10.128.2.60 (9/45%), 10.128.0.59 (6/30%)... 2 more
142# Users pantheon
143# Query_time distribution
144# 1us
145# 10us
146# 100us
147# 1ms
148# 10ms
149# 100ms
150# 1s ################################################################
151# 10s+
152# Tables
153# SHOW TABLE STATUS FROM `pantheon` LIKE 'elink_options'\G
154# SHOW CREATE TABLE `pantheon`.`elink_options`\G
155UPDATE `elink_options` SET `option_value` = '' WHERE `option_name` = 'rewrite_rules'\G
156# Converted for EXPLAIN
157# EXPLAIN /*!50100 PARTITIONS*/
158select `option_value` = '' from `elink_options` where `option_name` = 'rewrite_rules'\G
159
160# A software update is available:
161# * The current version for Percona::Toolkit is 3.0.5
162
163
164# 300ms user time, 40ms system time, 41.54M rss, 147.88M vsz
165# Current date: Fri Apr 19 18:09:51 2019
166# Hostname: dbserver-0aaeb0c1.c.pantheon-dmz.internal
167# Files: mysqld-slow-query.log
168# Overall: 3 total, 3 unique, 0.00 QPS, 0.00x concurrency ________________
169# Time range: 2019-01-27 09:13:02 to 2019-02-11 14:16:27
170# Attribute total min max avg 95% stddev median
171# ============ ======= ======= ======= ======= ======= ======= =======
172# Exec time 4s 1s 2s 1s 2s 265ms 1s
173# Lock time 167us 40us 72us 55us 69us 12us 54us
174# Rows sent 1 0 1 0.33 0.99 0.47 0
175# Rows examine 1 0 1 0.33 0.99 0.47 0
176# Query size 636 76 479 212 463.90 182.71 80.10
177
178# Profile
179# Rank Query ID Response time Calls R/Call V/M Item
180# ==== ================== ============= ===== ====== ===== ===============
181# 1 0x42CF7C975F4A106F 1.6763 43.2% 1 1.6763 0.00 SELECT pantheon._pt_heartbeat
182# 2 0x55217AC13337017A 1.1896 30.7% 1 1.1896 0.00 INSERT pantheon._pt_heartbeat
183# 3 0x64A0730403ECB7B9 1.0108 26.1% 1 1.0108 0.00 CREATE TABLE pantheon._pt_heartbeat `pantheon`.`_pt_heartbeat`
184
185# Query 1: 0 QPS, 0x concurrency, ID 0x42CF7C975F4A106F at byte 704 ______
186# This item is included in the report because it matches --limit.
187# Scores: V/M = 0.00
188# Time range: all events occurred at 2019-01-28 20:47:43
189# Attribute pct total min max avg 95% stddev median
190# ============ === ======= ======= ======= ======= ======= ======= =======
191# Count 33 1
192# Exec time 43 2s 2s 2s 2s 2s 0 2s
193# Lock time 23 40us 40us 40us 40us 40us 0 40us
194# Rows sent 100 1 1 1 1 1 0 1
195# Rows examine 100 1 1 1 1 1 0 1
196# Query size 11 76 76 76 76 76 0 76
197# String:
198# Databases pantheon
199# Hosts 127.0.0.1
200# Users pantheon
201# Query_time distribution
202# 1us
203# 10us
204# 100us
205# 1ms
206# 10ms
207# 100ms
208# 1s ################################################################
209# 10s+
210# Tables
211# SHOW TABLE STATUS FROM `pantheon` LIKE '_pt_heartbeat'\G
212# SHOW CREATE TABLE `pantheon`.`_pt_heartbeat`\G
213# EXPLAIN /*!50100 PARTITIONS*/
214SELECT 1 FROM `pantheon`.`_pt_heartbeat` WHERE server_id='387957038' LIMIT 1\G
215
216# Query 2: 0 QPS, 0x concurrency, ID 0x55217AC13337017A at byte 1004 _____
217# This item is included in the report because it matches --limit.
218# Scores: V/M = 0.00
219# Time range: all events occurred at 2019-02-11 14:16:27
220# Attribute pct total min max avg 95% stddev median
221# ============ === ======= ======= ======= ======= ======= ======= =======
222# Count 33 1
223# Exec time 30 1s 1s 1s 1s 1s 0 1s
224# Lock time 43 72us 72us 72us 72us 72us 0 72us
225# Rows sent 0 0 0 0 0 0 0 0
226# Rows examine 0 0 0 0 0 0 0 0
227# Query size 12 81 81 81 81 81 0 81
228# String:
229# Databases pantheon
230# Hosts 127.0.0.1
231# Users pantheon
232# Query_time distribution
233# 1us
234# 10us
235# 100us
236# 1ms
237# 10ms
238# 100ms
239# 1s ################################################################
240# 10s+
241# Tables
242# SHOW TABLE STATUS FROM `pantheon` LIKE '_pt_heartbeat'\G
243# SHOW CREATE TABLE `pantheon`.`_pt_heartbeat`\G
244INSERT INTO `pantheon`.`_pt_heartbeat` (ts, server_id) VALUES (NOW(), 2472347755)\G
245
246# Query 3: 0 QPS, 0x concurrency, ID 0x64A0730403ECB7B9 at byte 0 ________
247# This item is included in the report because it matches --limit.
248# Scores: V/M = 0.00
249# Time range: all events occurred at 2019-01-27 09:13:02
250# Attribute pct total min max avg 95% stddev median
251# ============ === ======= ======= ======= ======= ======= ======= =======
252# Count 33 1
253# Exec time 26 1s 1s 1s 1s 1s 0 1s
254# Lock time 32 55us 55us 55us 55us 55us 0 55us
255# Rows sent 0 0 0 0 0 0 0 0
256# Rows examine 0 0 0 0 0 0 0 0
257# Query size 75 479 479 479 479 479 0 479
258# String:
259# Databases pantheon
260# Hosts 127.0.0.1
261# Users pantheon
262# Query_time distribution
263# 1us
264# 10us
265# 100us
266# 1ms
267# 10ms
268# 100ms
269# 1s ################################################################
270# 10s+
271# Tables
272# SHOW TABLE STATUS FROM `pantheon` LIKE '_pt_heartbeat'\G
273# SHOW CREATE TABLE `pantheon`.`_pt_heartbeat`\G
274CREATE TABLE IF NOT EXISTS `pantheon`.`_pt_heartbeat` (
275 ts varchar(26) NOT NULL,
276 server_id int unsigned NOT NULL PRIMARY KEY,
277 file varchar(255) DEFAULT NULL, -- SHOW MASTER STATUS
278 position bigint unsigned DEFAULT NULL, -- SHOW MASTER STATUS
279 relay_master_log_file varchar(255) DEFAULT NULL, -- SHOW SLAVE STATUS
280 exec_master_log_pos bigint unsigned DEFAULT NULL -- SHOW SLAVE STATUS
281 )\G