Open saza-ku opened 1 year ago
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 32617 Time=0.00s (58s) Lock=0.00s (0s) Rows=0.2 (6476), 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: 23819 Time=0.00s (39s) Lock=0.00s (0s) Rows=0.5 (12048), 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: 39548 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: 542 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: 1084 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.5 (542), 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: 94961 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
#
Count: 542 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
commit
Count: 542 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: 542 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (542), isudns[isudns]@isucon1
select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'
Count: 1084 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 ...
# 12s user time, 70ms system time, 36.75M rss, 51.18M vsz
# Current date: Sat Nov 25 07:52:22 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 195.83k total, 20 unique, 2.39k QPS, 1.33x concurrency ________
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:52:10
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 109s 1us 12ms 555us 2ms 832us 89us
# Lock time 156ms 0 4ms 0 1us 17us 0
# Rows sent 19.15k 0 1 0.10 0.99 0.30 0
# Rows examine 86.43M 0 1.78k 462.79 1.69k 700.15 0
# Query size 15.16M 5 220 81.20 151.03 48.76 112.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x42EF7D7D98FBCC9723BF896E... 58.6989 53.9% 32617 0.0018 0.00 SELECT records
# 2 0x3D83BC87F3B3A00D571FFC81... 39.6094 36.4% 23819 0.0017 0.00 SELECT records
# 3 0x22279D81D51006139E0C7640... 4.7528 4.4% 39548 0.0001 0.00 SELECT domains domainmetadata
# 4 0x859BBB7E9D760686137A9444... 2.1344 2.0% 542 0.0039 0.00 DELETE records
# MISC 0xMISC 3.6432 3.3% 99304 0.0000 0.0 <16 ITEMS>
# Query 1: 494.20 QPS, 0.89x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 53152390
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 32617
# Exec time 53 59s 704us 12ms 2ms 3ms 571us 2ms
# Lock time 26 41ms 0 567us 1us 1us 3us 1us
# Rows sent 33 6.32k 0 1 0.20 0.99 0.40 0
# Rows examine 56 48.52M 1.25k 1.78k 1.52k 1.69k 146.72 1.46k
# Query size 29 4.41M 129 220 141.78 158.58 11.83 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='3e0oqxwogvk70.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='3e0oqxwogvk70.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.
# Query 2: 360.89 QPS, 0.60x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 20316600
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 23819
# Exec time 36 40s 657us 9ms 2ms 3ms 509us 2ms
# Lock time 18 30ms 0 383us 1us 1us 3us 1us
# Rows sent 61 11.77k 0 1 0.51 0.99 0.50 0.99
# Rows examine 41 35.50M 1.25k 1.78k 1.53k 1.69k 147.13 1.46k
# Query size 20 3.08M 126 219 135.46 151.03 11.17 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: 599.21 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 22246951
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 20 39548
# Exec time 4 5s 71us 5ms 120us 152us 105us 103us
# Lock time 39 62ms 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 28 4.30M 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: 8.21 QPS, 0.03x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 37857276
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 542
# Exec time 1 2s 2ms 9ms 4ms 6ms 860us 4ms
# Lock time 13 21ms 0 4ms 38us 1us 302us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 820.67k 1.25k 1.78k 1.51k 1.69k 152.78 1.46k
# Query size 0 45.26k 78 93 85.52 88.31 3.34 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='jun180.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN
select * from records where domain_id=4 and name='jun180.u.isucon.dev' and type='A'\G
http://localhost:19992/#menu_services;after=1700898648510;before=1700898728518
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250750
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 21694 Time=0.00s (16s) Lock=0.00s (0s) Rows=1.0 (21694), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id = N
Count: 722 Time=0.01s (8s) Lock=0.00s (0s) Rows=2.4 (1710), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Count: 72903 Time=0.00s (7s) Lock=0.00s (0s) Rows=1.0 (72903), isucon[isucon]@isucon1
SELECT * FROM tags WHERE id = N
Count: 473 Time=0.01s (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: 474 Time=0.01s (5s) Lock=0.00s (0s) Rows=9.9 (4692), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 14684 Time=0.00s (2s) Lock=0.00s (0s) Rows=5.0 (72908), isucon[isucon]@isucon1
SELECT * FROM livestream_tags WHERE livestream_id = N
Count: 21120 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.0 (21120), isucon[isucon]@isucon1
SELECT * FROM users WHERE id = N
Count: 21378 Time=0.00s (2s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@isucon1
COMMIT
Count: 765 Time=0.00s (2s) Lock=0.00s (0s) Rows=2454.4 (1877640), isucon[isucon]@isucon1
SELECT * FROM livecomments
Count: 81 Time=0.03s (2s) Lock=0.00s (0s) Rows=7808.7 (632501), isucon[isucon]@isucon1
SELECT * FROM livestreams
Reading from STDIN ...
# 16.6s user time, 70ms system time, 38.12M rss, 52.43M vsz
# Current date: Sat Nov 25 07:52:27 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 261.20k total, 68 unique, 2.97k QPS, 0.91x concurrency ________
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:52:16
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 80s 1us 117ms 307us 725us 2ms 80us
# Lock time 258ms 0 5ms 0 1us 23us 1us
# Rows sent 3.61M 0 7.78k 14.49 4.96 202.48 0.99
# Rows examine 57.26M 0 12.81k 229.85 1.33k 818.09 0.99
# Query size 11.77M 6 993 47.26 107.34 55.36 34.95
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0x38BC86A45F31C6B1EE32467... 16.0617 20.0% 21696 0.0007 0.00 SELECT themes
# 2 0x9EAD6C0CE525E3693EE27FF... 8.1699 10.2% 722 0.0113 0.00 SELECT livestreams
# 3 0xFBC5564AE716EAE82F20BFB... 7.2460 9.0% 72903 0.0001 0.00 SELECT tags
# 4 0xA3401CA3ABCC04C3AB221DB... 5.4083 6.7% 473 0.0114 0.00 UPDATE reservation_slots
# MISC 0xMISC 43.4397 54.1% 165410 0.0003 0.0 <64 ITEMS>
# Query 1: 249.38 QPS, 0.18x concurrency, ID 0x38BC86A45F31C6B1EE324671506C898A at byte 28437493
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:52:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 8 21696
# Exec time 19 16s 240us 15ms 740us 2ms 630us 568us
# Lock time 8 23ms 0 2ms 1us 1us 18us 1us
# Rows sent 0 21.19k 1 1 1 1 0 1
# Rows examine 46 26.65M 1000 1.50k 1.26k 1.46k 152.56 1.26k
# Query size 7 868.59k 38 41 41.00 40.45 0.13 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 = 1144\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: 1541
# filtered: 10.00
# Extra: Using where
# Query 2: 10.94 QPS, 0.12x concurrency, ID 0x9EAD6C0CE525E3693EE27FFC9AAF05A3 at byte 17167846
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 722
# Exec time 10 8s 4ms 40ms 11ms 20ms 5ms 10ms
# Lock time 0 632us 0 16us 0 1us 0 1us
# Rows sent 0 1.67k 0 21 2.37 7.70 2.75 0.99
# Rows examine 9 5.35M 7.32k 7.78k 7.58k 7.68k 176.49 7.31k
# Query size 0 32.42k 43 46 45.99 44.60 0.16 44.60
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ######################################################
# 10ms ################################################################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'livestreams'\G
# SHOW CREATE TABLE `livestreams`\G
# EXPLAIN
SELECT * FROM livestreams WHERE user_id = 1017\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: livestreams
# partitions: NULL
# type: ALL
# possible_keys: NULL
# key: NULL
# key_len: NULL
# ref: NULL
# rows: 7881
# filtered: 10.00
# Extra: Using where
# Query 3: 1.10k QPS, 0.11x concurrency, ID 0xFBC5564AE716EAE82F20BFB45F6C37E7 at byte 7464699
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 27 72903
# Exec time 9 7s 42us 7ms 99us 176us 184us 69us
# Lock time 32 84ms 0 3ms 1us 1us 18us 1us
# Rows sent 1 71.19k 1 1 1 1 0 1
# Rows examine 0 71.19k 1 1 1 1 0 1
# Query size 18 2.22M 31 33 31.96 31.70 0.43 31.70
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us ################################################################
# 100us ######
# 1ms #
# 10ms
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'tags'\G
# SHOW CREATE TABLE `tags`\G
# EXPLAIN
SELECT * FROM tags WHERE id = 96\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: tags
# partitions: NULL
# type: const
# possible_keys: PRIMARY
# key: PRIMARY
# key_len: 8
# ref: const
# rows: 1
# filtered: 100.00
# Extra: NULL
# Query 4: 7.17 QPS, 0.08x concurrency, ID 0xA3401CA3ABCC04C3AB221DB8AD5CBF26 at byte 30450250
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:50:48 to 2023-11-25T07:51:54
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 473
# Exec time 6 5s 5ms 45ms 11ms 22ms 5ms 10ms
# Lock time 0 709us 0 143us 1us 1us 8us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 6 3.95M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 45.27k 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 >= 1703358000 AND end_at <= 1703368800\G
# Converted for EXPLAIN
# EXPLAIN
select slot = slot - 1 from reservation_slots where start_at >= 1703358000 AND end_at <= 1703368800\G
http://localhost:19993/#menu_services;after=1700898648532;before=1700898728542
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250750
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700898648531;before=1700898724553
pprof