Open saza-ku opened 12 months ago
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 30318 Time=0.00s (60s) Lock=0.00s (0s) Rows=0.2 (6908), isudns[isudns]@isucon1
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=N and name='S' and domain_id=N
Count: 22517 Time=0.00s (41s) Lock=0.00s (0s) Rows=0.5 (11463), isudns[isudns]@isucon1
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=N and type='S' and name='S'
Count: 36504 Time=0.00s (4s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='S'
Count: 610 Time=0.00s (2s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
delete from records where domain_id=N and name='S' and type='S'
Count: 1220 Time=0.00s (2s) Lock=0.00s (0s) Rows=0.5 (610), isudns[isudns]@isucon1
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=N and type='S' and name='S' and domain_id=N
Count: 92248 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
#
Count: 610 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
commit
Count: 610 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
insert into records (content,ttl,prio,type,domain_id,disabled,name,ordername,auth) values ('S',N,N,'S',N,N,'S',NULL,N)
Count: 610 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (610), isudns[isudns]@isucon1
select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'
Count: 1221 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED
Reading from STDIN ...
# 11.4s user time, 50ms system time, 36.75M rss, 51.07M vsz
# Current date: Sat Nov 25 08:15:39 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 187.09k total, 20 unique, 2.28k QPS, 1.39x concurrency ________
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:28
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 114s 1us 16ms 609us 2ms 946us 84us
# Lock time 173ms 0 5ms 0 1us 25us 0
# Rows sent 19.14k 0 1 0.10 0.99 0.30 0
# Rows examine 82.59M 0 1.85k 462.92 1.69k 709.26 0
# Query size 14.29M 5 219 80.09 151.03 48.63 51.63
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x42EF7D7D98FBCC9723BF896E... 60.2989 52.9% 30318 0.0020 0.00 SELECT records
# 2 0x3D83BC87F3B3A00D571FFC81... 41.8776 36.7% 22517 0.0019 0.00 SELECT records
# 3 0x22279D81D51006139E0C7640... 4.8991 4.3% 36504 0.0001 0.00 SELECT domains domainmetadata
# 4 0x859BBB7E9D760686137A9444... 2.7221 2.4% 610 0.0045 0.00 DELETE records
# MISC 0xMISC 4.2906 3.8% 97136 0.0000 0.0 <16 ITEMS>
# Query 1: 452.51 QPS, 0.90x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 50363200
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 30318
# Exec time 52 60s 700us 16ms 2ms 3ms 710us 2ms
# Lock time 23 40ms 0 712us 1us 1us 5us 1us
# Rows sent 35 6.75k 0 1 0.23 0.99 0.42 0
# Rows examine 55 45.77M 1.25k 1.85k 1.55k 1.78k 169.04 1.53k
# Query size 28 4.08M 129 219 141.22 158.58 11.45 136.99
# String:
# Hosts isucon1
# Users isudns
# Query_time distribution
# 1us
# 10us
# 100us #
# 1ms ################################################################
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'records'\G
# SHOW CREATE TABLE `records`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='51i0ezsaeqo04xful6pq0.u.isucon.dev' and domain_id=4\G
# EXPLAIN failed: DBD::mysql::st execute failed: Table 'isupipe.records' doesn't exist [for Statement "EXPLAIN SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='51i0ezsaeqo04xful6pq0.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.
# Query 2: 336.07 QPS, 0.63x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 32583168
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 22517
# Exec time 36 42s 660us 12ms 2ms 3ms 689us 2ms
# Lock time 17 31ms 0 2ms 1us 1us 12us 1us
# Rows sent 58 11.19k 0 1 0.51 0.99 0.50 0.99
# Rows examine 41 34.05M 1.25k 1.85k 1.55k 1.78k 168.93 1.53k
# Query size 20 2.90M 126 218 134.95 151.03 10.78 124.25
# String:
# Hosts isucon1
# Users isudns
# Query_time distribution
# 1us
# 10us
# 100us #
# 1ms ################################################################
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'records'\G
# SHOW CREATE TABLE `records`\G
# EXPLAIN
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and type='SOA' and name='u.isucon.dev'\G
# EXPLAIN failed: DBD::mysql::st execute failed: Table 'isupipe.records' doesn't exist [for Statement "EXPLAIN SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and type='SOA' and name='u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.
# Query 3: 544.84 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 4780983
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 19 36504
# Exec time 4 5s 73us 6ms 134us 185us 133us 108us
# Lock time 35 61ms 0 2ms 1us 1us 13us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 27 3.97M 114 114 114 114 0 114
# String:
# Hosts isucon1
# Users isudns
# Query_time distribution
# 1us
# 10us ########
# 100us ################################################################
# 1ms #
# 10ms
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'domains'\G
# SHOW CREATE TABLE `domains`\G
# SHOW TABLE STATUS LIKE 'domainmetadata'\G
# SHOW CREATE TABLE `domainmetadata`\G
# EXPLAIN
select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='u.isucon.dev'\G
# EXPLAIN failed: DBD::mysql::st execute failed: Table 'isupipe.domains' doesn't exist [for Statement "EXPLAIN select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.
# Query 4: 9.10 QPS, 0.04x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 46405765
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 610
# Exec time 2 3s 2ms 13ms 4ms 7ms 1ms 4ms
# Lock time 22 38ms 0 5ms 62us 1us 428us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 1 943.88k 1.25k 1.84k 1.55k 1.78k 173.27 1.53k
# Query size 0 50.92k 78 93 85.49 88.31 3.30 84.10
# String:
# Hosts isucon1
# Users isudns
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ################################################################
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'records'\G
# SHOW CREATE TABLE `records`\G
delete from records where domain_id=4 and name='lkato1.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN
select * from records where domain_id=4 and name='lkato1.u.isucon.dev' and type='A'\G
http://localhost:19992/#menu_services;after=1700900046201;before=1700900126209
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250814
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 64437 Time=0.00s (57s) Lock=0.00s (0s) Rows=1.0 (64437), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id = N
Count: 54385 Time=0.00s (12s) Lock=0.00s (0s) Rows=4.5 (247440), isucon[isucon]@isucon1
SELECT livestream_id, tags.id AS tag_id, tags.name as tag_name FROM livestream_tags as l LEFT JOIN tags ON l.tag_id = tags.id WHERE livestream_id = N
Count: 516 Time=0.02s (10s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@isucon1
UPDATE reservation_slots SET slot = slot - N WHERE start_at >= N AND end_at <= N
Count: 517 Time=0.02s (8s) Lock=0.00s (0s) Rows=10.0 (5150), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 63778 Time=0.00s (7s) Lock=0.00s (0s) Rows=1.0 (63778), isucon[isucon]@isucon1
SELECT * FROM users WHERE id = N
Count: 372 Time=0.02s (6s) Lock=0.00s (0s) Rows=3.2 (1208), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Count: 25443 Time=0.00s (3s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@isucon1
COMMIT
Count: 31500 Time=0.00s (3s) Lock=0.00s (0s) Rows=1.0 (31500), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE id = N
Count: 3591 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.3 (4757), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id IN (N, N)
Count: 2770 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.0 (2770), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id IN (N)
Reading from STDIN ...
# 21.3s user time, 90ms system time, 38.00M rss, 52.24M vsz
# Current date: Sat Nov 25 08:15:50 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 332.55k total, 65 unique, 4.01k QPS, 1.63x concurrency ________
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:29
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 136s 1us 120ms 407us 1ms 2ms 113us
# Lock time 372ms 0 7ms 1us 1us 26us 1us
# Rows sent 2.11M 0 7.81k 6.66 4.96 135.06 0.99
# Rows examine 110.46M 0 16.55k 348.29 1.39k 804.66 0.99
# Query size 19.60M 6 444 61.79 151.03 51.51 40.45
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0x38BC86A45F31C6B1EE32467... 57.9198 42.7% 64437 0.0009 0.00 SELECT themes
# 2 0xA0E56FBF29E0231425D4BA3... 12.5312 9.2% 54385 0.0002 0.00 SELECT livestream_tags tags
# 3 0xA3401CA3ABCC04C3AB221DB... 10.0427 7.4% 516 0.0195 0.00 UPDATE reservation_slots
# 4 0x7F9C0C0BA9473953B723EE1... 8.2912 6.1% 517 0.0160 0.00 SELECT reservation_slots
# MISC 0xMISC 46.7866 34.5% 212699 0.0002 0.0 <61 ITEMS>
# Query 1: 961.75 QPS, 0.86x concurrency, ID 0x38BC86A45F31C6B1EE324671506C898A at byte 52473989
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 19 64437
# Exec time 42 58s 238us 16ms 898us 2ms 838us 626us
# Lock time 16 63ms 0 2ms 0 1us 11us 1us
# Rows sent 2 62.93k 1 1 1 1 0 1
# Rows examine 72 79.99M 1000 1.57k 1.27k 1.53k 172.73 1.26k
# Query size 12 2.51M 38 41 40.89 40.45 0.59 40.45
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms ################
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'themes'\G
# SHOW CREATE TABLE `themes`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM themes WHERE user_id = 1249\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: themes
# partitions: NULL
# type: ALL
# possible_keys: NULL
# key: NULL
# key_len: NULL
# ref: NULL
# rows: 1610
# filtered: 10.00
# Extra: Using where
# Query 2: 811.72 QPS, 0.19x concurrency, ID 0xA0E56FBF29E0231425D4BA3CE21653D3 at byte 17295234
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 54385
# Exec time 9 13s 77us 45ms 230us 541us 597us 144us
# Lock time 28 105ms 0 5ms 1us 1us 43us 1us
# Rows sent 11 241.64k 0 11 4.55 4.96 1.18 4.96
# Rows examine 0 483.28k 0 22 9.10 9.83 2.34 9.83
# Query size 40 7.93M 150 153 152.98 151.03 0.29 151.03
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us #
# 100us ################################################################
# 1ms #
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'livestream_tags'\G
# SHOW CREATE TABLE `livestream_tags`\G
# SHOW TABLE STATUS LIKE 'tags'\G
# SHOW CREATE TABLE `tags`\G
# EXPLAIN
SELECT livestream_id, tags.id AS tag_id, tags.name as tag_name FROM livestream_tags as l LEFT JOIN tags ON l.tag_id = tags.id WHERE livestream_id = 4638\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: l
# partitions: NULL
# type: ref
# possible_keys: livestream_id
# key: livestream_id
# key_len: 8
# ref: const
# rows: 1
# filtered: 100.00
# Extra: NULL
# *************************** 2. row ***************************
# id: 1
# select_type: SIMPLE
# table: tags
# partitions: NULL
# type: eq_ref
# possible_keys: PRIMARY
# key: PRIMARY
# key_len: 8
# ref: isupipe.l.tag_id
# rows: 1
# filtered: 100.00
# Extra: NULL
# Query 3: 7.70 QPS, 0.15x concurrency, ID 0xA3401CA3ABCC04C3AB221DB8AD5CBF26 at byte 40749700
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 516
# Exec time 7 10s 5ms 69ms 19ms 38ms 10ms 17ms
# Lock time 0 443us 0 2us 0 1us 0 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 3 4.31M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 49.38k 98 98 98 98 0 98
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ##########
# 10ms ################################################################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'reservation_slots'\G
# SHOW CREATE TABLE `reservation_slots`\G
UPDATE reservation_slots SET slot = slot - 1 WHERE start_at >= 1702987200 AND end_at <= 1703023200\G
# Converted for EXPLAIN
# EXPLAIN
select slot = slot - 1 from reservation_slots where start_at >= 1702987200 AND end_at <= 1703023200\G
# Query 4: 7.72 QPS, 0.12x concurrency, ID 0x7F9C0C0BA9473953B723EE16C08655F1 at byte 85171566
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:14:06 to 2023-11-25T08:15:13
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 517
# Exec time 6 8s 5ms 50ms 16ms 30ms 7ms 14ms
# Lock time 0 521us 0 14us 1us 1us 0 1us
# Rows sent 0 5.03k 1 21 9.96 19.46 5.87 9.83
# Rows examine 3 4.32M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 48.47k 96 96 96 96 0 96
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ################
# 10ms ################################################################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'reservation_slots'\G
# SHOW CREATE TABLE `reservation_slots`\G
# EXPLAIN
SELECT * FROM reservation_slots WHERE start_at >= 1704531600 AND end_at <= 1704567600 FOR UPDATE\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: reservation_slots
# partitions: NULL
# type: ALL
# possible_keys: NULL
# key: NULL
# key_len: NULL
# ref: NULL
# rows: 8593
# filtered: 11.11
# Extra: Using where
http://localhost:19993/#menu_services;after=1700900046198;before=1700900126205
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250814
84,529
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700900046200;before=1700900122266
pprof