Open saza-ku opened 1 year ago
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 36064 Time=0.00s (56s) Lock=0.00s (0s) Rows=0.1 (3012), 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: 24872 Time=0.00s (36s) Lock=0.00s (0s) Rows=0.5 (12481), 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: 45324 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: 397 Time=0.00s (1s) 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: 794 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.5 (397), 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: 95559 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
#
Count: 397 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
commit
Count: 397 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: 397 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (397), isudns[isudns]@isucon1
select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'
Count: 795 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 ...
# 12.5s user time, 80ms system time, 36.75M rss, 51.07M vsz
# Current date: Sat Nov 25 04:03:24 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 205.40k total, 20 unique, 2.50k QPS, 1.25x concurrency ________
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:03:11
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 103s 1us 12ms 499us 2ms 708us 89us
# Lock time 146ms 0 3ms 0 1us 12us 1us
# Rows sent 15.91k 0 1 0.08 0.99 0.27 0
# Rows examine 89.25M 0 1.64k 455.64 1.53k 678.17 0
# Query size 16.37M 5 219 83.55 151.03 48.83 112.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x42EF7D7D98FBCC9723BF896E... 56.9088 55.5% 36064 0.0016 0.00 SELECT records
# 2 0x3D83BC87F3B3A00D571FFC81... 36.5413 35.6% 24872 0.0015 0.00 SELECT records
# 3 0x22279D81D51006139E0C7640... 4.9361 4.8% 45324 0.0001 0.00 SELECT domains domainmetadata
# 4 0x859BBB7E9D760686137A9444... 1.3927 1.4% 397 0.0035 0.00 DELETE records
# MISC 0xMISC 2.7312 2.7% 98743 0.0000 0.0 <16 ITEMS>
# Query 1: 530.35 QPS, 0.84x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 7595551
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 17 36064
# Exec time 55 57s 704us 8ms 2ms 2ms 358us 2ms
# Lock time 30 44ms 0 2ms 1us 1us 13us 1us
# Rows sent 18 2.94k 0 1 0.08 0.99 0.27 0
# Rows examine 58 51.84M 1.25k 1.64k 1.47k 1.61k 106.36 1.46k
# Query size 29 4.91M 129 219 142.65 158.58 12.32 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='ebi2ru69cwjkkp0.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='ebi2ru69cwjkkp0.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.
# Query 2: 365.76 QPS, 0.54x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 2800419
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 24872
# Exec time 35 37s 658us 12ms 1ms 2ms 336us 1ms
# Lock time 19 28ms 0 155us 1us 1us 1us 1us
# Rows sent 76 12.19k 0 1 0.50 0.99 0.50 0.99
# Rows examine 40 35.73M 1.25k 1.64k 1.47k 1.61k 106.82 1.46k
# Query size 19 3.24M 126 218 136.63 151.03 11.74 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='vjfhqwlecs4h9z2bqg0zu6q0.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='vjfhqwlecs4h9z2bqg0zu6q0.u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.
# Query 3: 666.53 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 5485870
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 22 45324
# Exec time 4 5s 72us 4ms 108us 125us 76us 98us
# Lock time 42 62ms 0 956us 1us 1us 4us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 30 4.93M 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: 5.84 QPS, 0.02x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 34829590
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 397
# Exec time 1 1s 2ms 10ms 4ms 4ms 658us 3ms
# Lock time 7 11ms 0 3ms 28us 1us 245us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 573.01k 1.25k 1.64k 1.44k 1.61k 114.79 1.39k
# Query size 0 33.21k 78 93 85.66 88.31 3.33 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='yutatanaka0.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN
select * from records where domain_id=4 and name='yutatanaka0.u.isucon.dev' and type='A'\G
http://localhost:19992/#menu_services;after=1700884909176;before=1700884989184
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250401
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 30668 Time=0.01s (159s) Lock=0.00s (0s) Rows=0.9 (26408), isucon[isucon]@isucon1
SELECT image FROM icons WHERE user_id = N
Count: 26108 Time=0.00s (20s) Lock=0.00s (0s) Rows=1.0 (26108), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id = N
Count: 1508 Time=0.01s (18s) Lock=0.00s (0s) Rows=1.0 (1508), isucon[isucon]@isucon1
SELECT slot FROM reservation_slots WHERE start_at = N AND end_at = N
Count: 567 Time=0.03s (14s) Lock=0.00s (0s) Rows=0.1 (29), isucon[isucon]@isucon1
SELECT id, user_id, livestream_id, word FROM ng_words WHERE user_id = N AND livestream_id = N
Count: 74313 Time=0.00s (7s) Lock=0.00s (0s) Rows=1.0 (74313), isucon[isucon]@isucon1
SELECT * FROM tags WHERE id = N
Count: 240 Time=0.03s (7s) Lock=0.00s (0s) Rows=1.1 (259), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Count: 161 Time=0.04s (5s) 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: 162 Time=0.03s (5s) Lock=0.00s (0s) Rows=9.3 (1508), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 17430 Time=0.00s (5s) Lock=0.00s (0s) Rows=4.3 (74313), isucon[isucon]@isucon1
SELECT * FROM livestream_tags WHERE livestream_id = N
Count: 404 Time=0.01s (4s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@isucon1
INSERT INTO icons (user_id, icon_path, image) VALUES (N, 'S', _binary'S')
Reading from STDIN ...
# 14.4s user time, 120ms system time, 38.76M rss, 53.06M vsz
# Current date: Sat Nov 25 04:03:29 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 216.59k total, 64 unique, 2.52k QPS, 3.11x concurrency ________
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:03:15
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 267s 1us 80ms 1ms 7ms 4ms 103us
# Lock time 632ms 0 44ms 2us 1us 197us 1us
# Rows sent 418.03k 0 7.32k 1.98 4.96 35.61 0.99
# Rows examine 63.17M 0 14.01k 305.83 1.20k 1.17k 0.99
# Query size 35.24M 6 175.36k 170.63 54.21 2.98k 34.95
# Profile
# Rank Query ID Response time Calls R/Call V/M Ite
# ==== ============================ ============== ====== ====== ===== ===
# 1 0x84B457C910C4A79FC9EBECB... 160.0194 59.8% 30668 0.0052 0.01 SELECT icons
# 2 0x38BC86A45F31C6B1EE32467... 20.7905 7.8% 26108 0.0008 0.00 SELECT themes
# 3 0x59F1B6DD8D9FEC059E55B3B... 18.7840 7.0% 1508 0.0125 0.00 SELECT reservation_slots
# 4 0x64CC8A4E8E4B39020337559... 14.7059 5.5% 567 0.0259 0.00 SELECT ng_words
# MISC 0xMISC 53.1464 19.9% 157737 0.0003 0.0 <60 ITEMS>
# Query 1: 451 QPS, 2.35x concurrency, ID 0x84B457C910C4A79FC9EBECB8B1065C66 at byte 57585876
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 30668
# Exec time 59 160s 44us 62ms 5ms 17ms 6ms 3ms
# Lock time 5 34ms 0 2ms 1us 1us 15us 1us
# Rows sent 6 25.79k 0 1 0.86 0.99 0.34 0.99
# Rows examine 8 5.21M 0 389 178.15 346.17 109.04 166.51
# Query size 3 1.28M 41 44 43.88 42.48 0.22 42.48
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us ####
# 100us #####################
# 1ms ################################################################
# 10ms #####################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'icons'\G
# SHOW CREATE TABLE `icons`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT image FROM icons WHERE user_id = 1016\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: icons
# partitions: NULL
# type: ALL
# possible_keys: NULL
# key: NULL
# key_len: NULL
# ref: NULL
# rows: 386
# filtered: 10.00
# Extra: Using where
# Query 2: 383.94 QPS, 0.31x concurrency, ID 0x38BC86A45F31C6B1EE324671506C898A at byte 46388038
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 26108
# Exec time 7 21s 237us 27ms 796us 2ms 896us 568us
# Lock time 4 26ms 0 627us 0 1us 4us 1us
# Rows sent 6 25.50k 1 1 1 1 0 1
# Rows examine 46 29.51M 1000 1.36k 1.16k 1.33k 111.95 1.14k
# Query size 2 1.02M 38 41 40.89 40.45 0.57 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
SELECT * FROM themes WHERE user_id = 1114\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: 1396
# filtered: 10.00
# Extra: Using where
# Query 3: 22.18 QPS, 0.28x concurrency, ID 0x59F1B6DD8D9FEC059E55B3BFD624E8C3 at byte 8714339
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 1508
# Exec time 7 19s 2ms 41ms 12ms 23ms 7ms 12ms
# Lock time 0 5ms 0 2ms 3us 1us 66us 1us
# Rows sent 0 1.47k 1 1 1 1 0 1
# Rows examine 19 12.60M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 126.65k 86 86 86 86 0 86
# 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 slot FROM reservation_slots WHERE start_at = 1700953200 AND end_at = 1700956800\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: 1.00
# Extra: Using where
# Query 4: 8.34 QPS, 0.22x concurrency, ID 0x64CC8A4E8E4B390203375597CE4D611F at byte 12087703
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T04:01:49 to 2023-11-25T04:02:57
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 567
# Exec time 5 15s 4ms 49ms 26ms 40ms 9ms 26ms
# Lock time 0 633us 0 23us 1us 1us 1us 1us
# Rows sent 0 29 0 2 0.05 0 0.25 0
# Rows examine 12 7.75M 14.00k 14.01k 14.00k 13.78k 0 13.78k
# Query size 0 54.81k 97 99 98.99 97.36 0.27 97.36
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ###
# 10ms ################################################################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'ng_words'\G
# SHOW CREATE TABLE `ng_words`\G
# EXPLAIN
SELECT id, user_id, livestream_id, word FROM ng_words WHERE user_id = 1019 AND livestream_id = 7534\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: ng_words
# partitions: NULL
# type: ALL
# possible_keys: NULL
# key: NULL
# key_len: NULL
# ref: NULL
# rows: 14155
# filtered: 1.00
# Extra: Using where
http://localhost:19993/#menu_services;after=1700884909178;before=1700884989185
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250401
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700884909167;before=1700884985326
pprof