Open saza-ku opened 7 months ago
+-------+--------+-----+-------+-------+-------+-------+-------+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-------+-------+-------+-------+-------+
| 1 | GET | / | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+-----+-------+-------+-------+-------+-------+
Count: 52625 Time=0.00s (8s) Lock=0.00s (0s) Rows=4.6 (242711), 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: 716 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: 60438 Time=0.00s (5s) Lock=0.00s (0s) Rows=1.0 (60438), isucon[isucon]@isucon1
SELECT * FROM users WHERE id = N
Count: 717 Time=0.01s (5s) Lock=0.00s (0s) Rows=10.1 (7216), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 26332 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.0 (26332), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE id = N
Count: 286 Time=0.01s (2s) Lock=0.00s (0s) Rows=4.3 (1233), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Count: 3113 Time=0.00s (1s) Lock=0.00s (0s) Rows=1.2 (3810), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id IN (N, N)
Count: 22354 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@isucon1
COMMIT
Count: 2680 Time=0.00s (1s) Lock=0.00s (0s) Rows=1.0 (2680), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id IN (N)
Count: 370 Time=0.00s (1s) Lock=0.00s (0s) Rows=2912.6 (1077670), isucon[isucon]@isucon1
SELECT * FROM livecomments
Reading from STDIN ...
# 15.5s user time, 70ms system time, 37.88M rss, 52.17M vsz
# Current date: Sat Nov 25 08:41:52 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 244.81k total, 65 unique, 2.95k QPS, 0.59x concurrency ________
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:37
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 49s 1us 63ms 199us 384us 934us 89us
# Lock time 210ms 0 3ms 0 1us 9us 1us
# Rows sent 1.89M 0 7.99k 8.09 4.96 142.30 0.99
# Rows examine 30.12M 0 14.24k 129.02 420.77 797.49 0.99
# Query size 15.87M 6 453 67.96 151.03 57.36 40.45
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0xA0E56FBF29E0231425D4BA3... 8.5243 17.4% 52625 0.0002 0.00 SELECT livestream_tags tags
# 2 0xEA1E6309EEEFF9A6831AD2F... 5.8830 12.0% 60438 0.0001 0.00 SELECT users
# 3 0xA3401CA3ABCC04C3AB221DB... 5.8607 12.0% 716 0.0082 0.00 UPDATE reservation_slots
# 4 0x7F9C0C0BA9473953B723EE1... 5.7327 11.7% 717 0.0080 0.00 SELECT reservation_slots
# MISC 0xMISC 22.9357 46.9% 130317 0.0002 0.0 <61 ITEMS>
# Query 1: 773.90 QPS, 0.13x concurrency, ID 0xA0E56FBF29E0231425D4BA3CE21653D3 at byte 10121246
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 21 52625
# Exec time 17 9s 74us 50ms 161us 224us 583us 138us
# Lock time 29 62ms 0 942us 1us 1us 6us 1us
# Rows sent 12 237.02k 0 11 4.61 4.96 1.11 4.96
# Rows examine 1 474.04k 0 22 9.22 9.83 2.19 9.83
# Query size 48 7.68M 150 153 152.99 151.03 0.25 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 /*!50100 PARTITIONS*/
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 = 7616\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: 5
# 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 2: 888.79 QPS, 0.09x concurrency, ID 0xEA1E6309EEEFF9A6831AD2FB940FC23C at byte 52692847
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 24 60438
# Exec time 12 6s 49us 53ms 97us 119us 512us 76us
# Lock time 26 55ms 0 772us 0 1us 5us 1us
# Rows sent 3 59.02k 1 1 1 1 0 1
# Rows examine 0 59.02k 1 1 1 1 0 1
# Query size 12 2.01M 32 35 34.90 34.95 0.54 34.95
# String:
# Hosts isucon1
# Users isucon
# Query_time distribution
# 1us
# 10us ################################################################
# 100us #########
# 1ms #
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'users'\G
# SHOW CREATE TABLE `users`\G
# EXPLAIN
SELECT * FROM users WHERE id = 1296\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: users
# partitions: NULL
# type: const
# possible_keys: PRIMARY
# key: PRIMARY
# key_len: 8
# ref: const
# rows: 1
# filtered: 100.00
# Extra: NULL
# Query 3: 10.53 QPS, 0.09x concurrency, ID 0xA3401CA3ABCC04C3AB221DB8AD5CBF26 at byte 65669001
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 716
# Exec time 11 6s 5ms 27ms 8ms 12ms 2ms 8ms
# Lock time 0 638us 0 12us 0 1us 0 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 19 5.98M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 68.52k 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 >= 1706079600 AND end_at <= 1706126400\G
# Converted for EXPLAIN
# EXPLAIN
select slot = slot - 1 from reservation_slots where start_at >= 1706079600 AND end_at <= 1706126400\G
# Query 4: 10.54 QPS, 0.08x concurrency, ID 0x7F9C0C0BA9473953B723EE16C08655F1 at byte 64542081
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 717
# Exec time 11 6s 5ms 35ms 8ms 12ms 2ms 7ms
# Lock time 0 984us 0 205us 1us 1us 7us 1us
# Rows sent 0 7.05k 1 21 10.06 19.46 5.81 9.83
# Rows examine 19 5.99M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 67.22k 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 >= 1706562000 AND end_at <= 1706601600 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: 8773
# filtered: 11.11
# Extra: Using where
http://localhost:19993/#menu_services;after=1700901614552;before=1700901694560
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250840
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 121523 Time=0.00s (14s) 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: 95854 Time=0.00s (13s) Lock=0.00s (0s) Rows=0.1 (6023), 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: 65206 Time=0.00s (8s) Lock=0.00s (0s) Rows=0.5 (32434), 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: 258072 Time=0.00s (3s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
#
Count: 548 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: 1096 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.5 (548), 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: 548 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: 548 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (548), isudns[isudns]@isucon1
select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'
Count: 1096 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED
Count: 548 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
commit
Reading from STDIN ...
# 33.5s user time, 140ms system time, 36.88M rss, 51.20M vsz
# Current date: Sat Nov 25 08:42:14 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 545.60k total, 24 unique, 5.20k QPS, 0.42x concurrency ________
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:59
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 44s 1us 15ms 80us 176us 138us 89us
# Lock time 397ms 0 2ms 0 1us 4us 1us
# Rows sent 38.65k 0 9 0.07 0.99 0.26 0
# Rows examine 873.03k 0 1.78k 1.64 0.99 48.26 0
# Query size 43.32M 5 222 83.25 151.03 48.82 112.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0x22279D81D51006139E0C764... 14.9391 34.0% 121523 0.0001 0.00 SELECT domains domainmetadata
# 2 0x42EF7D7D98FBCC9723BF896... 13.9099 31.7% 95854 0.0001 0.00 SELECT records
# 3 0x3D83BC87F3B3A00D571FFC8... 9.0110 20.5% 65206 0.0001 0.00 SELECT records
# 4 0x8F7679D452333ED3C7D60D2... 3.0613 7.0% 250666 0.0000 0.00 ADMIN RESET STMT
# MISC 0xMISC 2.9935 6.8% 12350 0.0002 0.0 <20 ITEMS>
# Query 1: 1.79k QPS, 0.22x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 48993634
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 22 121523
# Exec time 34 15s 70us 5ms 122us 194us 55us 108us
# Lock time 46 184ms 0 2ms 1us 1us 6us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 30 13.21M 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 /*!50100 PARTITIONS*/
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 2: 1.41k QPS, 0.20x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 48995098
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 17 95854
# Exec time 31 14s 82us 5ms 145us 224us 57us 131us
# Lock time 31 124ms 0 514us 1us 1us 3us 1us
# Rows sent 15 5.88k 0 1 0.06 0.99 0.24 0
# Rows examine 0 5.88k 0 1 0.06 0.99 0.24 0
# Query size 30 13.07M 129 222 142.96 158.58 12.50 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
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='agx1d81s6gvjoa8och8cmwwx0.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='agx1d81s6gvjoa8och8cmwwx0.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.
# Query 3: 958.91 QPS, 0.13x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 144169243
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 11 65206
# Exec time 20 9s 79us 4ms 138us 214us 54us 119us
# Lock time 20 83ms 0 450us 1us 1us 3us 1us
# Rows sent 81 31.67k 0 1 0.50 0.99 0.50 0
# Rows examine 3 34.61k 0 1 0.54 0.99 0.49 0.99
# Query size 19 8.52M 126 221 137.02 151.03 11.95 130.47
# 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='03qh40cvzxsjzbd5j1mpivhz0.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='03qh40cvzxsjzbd5j1mpivhz0.u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.
# Query 4: 3.69k QPS, 0.05x concurrency, ID 0x8F7679D452333ED3C7D60D22131CEFD4 at byte 43693473
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T08:40:14 to 2023-11-25T08:41:22
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 45 250666
# Exec time 6 3s 6us 4ms 12us 21us 13us 9us
# Lock time 0 0 0 0 0 0 0 0
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 18 7.89M 33 33 33 33 0 33
# String:
# Hosts isucon1
# Users isudns
# Query_time distribution
# 1us ###################################
# 10us ################################################################
# 100us #
# 1ms #
# 10ms
# 100ms
# 1s
# 10s+
administrator command: Reset stmt\G
http://localhost:19992/#menu_services;after=1700901614584;before=1700901694594
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250840
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700901614552;before=1700901690607
pprof