Open saza-ku opened 10 months ago
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 32564 Time=0.00s (58s) Lock=0.00s (0s) Rows=0.2 (5232), 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: 23406 Time=0.00s (39s) Lock=0.00s (0s) Rows=0.5 (11867), 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: 39984 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: 563 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: 1126 Time=0.00s (2s) Lock=0.00s (0s) Rows=0.5 (563), 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: 94888 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
#
Count: 563 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
commit
Count: 563 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: 563 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (563), isudns[isudns]@isucon1
select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'
Count: 1126 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.2s user time, 50ms system time, 36.75M rss, 51.07M vsz
# Current date: Sat Nov 25 07:07:10 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 195.92k total, 20 unique, 2.36k QPS, 1.31x concurrency ________
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:58
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 109s 1us 14ms 555us 2ms 841us 89us
# Lock time 177ms 0 4ms 0 1us 23us 0
# Rows sent 17.80k 0 1 0.09 0.99 0.29 0
# Rows examine 85.88M 0 1.80k 459.65 1.69k 700.05 0
# Query size 15.17M 5 221 81.19 151.03 48.74 112.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x42EF7D7D98FBCC9723BF896E... 58.7695 54.0% 32564 0.0018 0.00 SELECT records
# 2 0x3D83BC87F3B3A00D571FFC81... 39.1313 36.0% 23406 0.0017 0.00 SELECT records
# 3 0x22279D81D51006139E0C7640... 4.7903 4.4% 39984 0.0001 0.00 SELECT domains domainmetadata
# 4 0x859BBB7E9D760686137A9444... 2.3082 2.1% 563 0.0041 0.00 DELETE records
# MISC 0xMISC 3.7439 3.4% 99399 0.0000 0.0 <16 ITEMS>
# Query 1: 471.94 QPS, 0.85x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 39364646
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:44
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 32564
# Exec time 54 59s 701us 11ms 2ms 3ms 592us 2ms
# Lock time 24 43ms 0 2ms 1us 1us 10us 1us
# Rows sent 28 5.11k 0 1 0.16 0.99 0.36 0
# Rows examine 56 48.48M 1.25k 1.80k 1.52k 1.69k 155.34 1.46k
# Query size 29 4.41M 129 221 141.84 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='*.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='*.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.
# Query 2: 339.22 QPS, 0.57x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 6508202
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:44
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 11 23406
# Exec time 35 39s 659us 14ms 2ms 3ms 543us 2ms
# Lock time 18 33ms 0 2ms 1us 1us 16us 1us
# Rows sent 65 11.59k 0 1 0.51 0.99 0.50 0.99
# Rows examine 40 34.88M 1.25k 1.80k 1.53k 1.69k 155.52 1.46k
# Query size 19 3.03M 126 220 135.66 151.03 11.20 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='5isvhr8t5v77a50.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='5isvhr8t5v77a50.u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.
# Query 3: 579.48 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 24748768
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:44
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 20 39984
# Exec time 4 5s 71us 4ms 119us 152us 99us 103us
# Lock time 34 60ms 0 936us 1us 1us 7us 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.35M 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.28 QPS, 0.03x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 54894723
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:36 to 2023-11-25T07:06:44
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 563
# Exec time 2 2s 2ms 10ms 4ms 6ms 1ms 4ms
# Lock time 21 38ms 0 4ms 66us 1us 401us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 858.23k 1.25k 1.80k 1.52k 1.69k 160.73 1.46k
# Query size 0 47.03k 78 93 85.54 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='sayuri170.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN
select * from records where domain_id=4 and name='sayuri170.u.isucon.dev' and type='A'\G
http://localhost:19992/#menu_services;after=1700895935825;before=1700896015833
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250705
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 41379 Time=0.00s (33s) Lock=0.00s (0s) Rows=1.0 (41379), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id = N
Count: 159332 Time=0.00s (14s) Lock=0.00s (0s) Rows=1.0 (159332), isucon[isucon]@isucon1
SELECT * FROM tags WHERE id = N
Count: 487 Time=0.02s (9s) 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: 488 Time=0.02s (7s) Lock=0.00s (0s) Rows=9.9 (4816), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 26359 Time=0.00s (6s) Lock=0.00s (0s) Rows=0.8 (21709), isucon[isucon]@isucon1
SELECT icon_path FROM icons WHERE user_id = N
Count: 2603 Time=0.00s (5s) Lock=0.00s (0s) Rows=9.9 (25791), isucon[isucon]@isucon1
SELECT * FROM livecomments WHERE livestream_id = N ORDER BY created_at DESC
Count: 35261 Time=0.00s (5s) Lock=0.00s (0s) Rows=4.5 (159338), isucon[isucon]@isucon1
SELECT * FROM livestream_tags WHERE livestream_id = N
Count: 2637 Time=0.00s (5s) Lock=0.00s (0s) Rows=9.6 (25206), isucon[isucon]@isucon1
SELECT * FROM reactions WHERE livestream_id = N ORDER BY created_at DESC
Count: 40785 Time=0.00s (4s) Lock=0.00s (0s) Rows=1.0 (40785), isucon[isucon]@isucon1
SELECT * FROM users WHERE id = N
Count: 233 Time=0.02s (4s) Lock=0.00s (0s) Rows=3.6 (839), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Reading from STDIN ...
# 28.1s user time, 110ms system time, 38.00M rss, 52.32M vsz
# Current date: Sat Nov 25 07:07:28 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 468.06k total, 66 unique, 5.51k QPS, 1.46x concurrency ________
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:07:00
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 124s 1us 79ms 264us 761us 1ms 76us
# Lock time 430ms 0 7ms 0 1us 23us 1us
# Rows sent 1.57M 0 7.79k 3.52 4.96 91.52 0.99
# Rows examine 91.13M 0 13.07k 204.14 1.26k 644.67 0.99
# Query size 16.91M 6 453 37.89 62.76 25.85 31.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0x38BC86A45F31C6B1EE32467... 33.6618 27.2% 41379 0.0008 0.00 SELECT themes
# 2 0xFBC5564AE716EAE82F20BFB... 14.5671 11.8% 159332 0.0001 0.00 SELECT tags
# 3 0xA3401CA3ABCC04C3AB221DB... 9.0925 7.4% 487 0.0187 0.00 UPDATE reservation_slots
# 4 0x7F9C0C0BA9473953B723EE1... 7.6300 6.2% 488 0.0156 0.00 SELECT reservation_slots
# MISC 0xMISC 58.7400 47.5% 266375 0.0002 0.0 <62 ITEMS>
# Query 1: 608.51 QPS, 0.50x concurrency, ID 0x38BC86A45F31C6B1EE324671506C898A at byte 97168231
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:43
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 8 41379
# Exec time 27 34s 236us 13ms 813us 2ms 690us 596us
# Lock time 10 47ms 0 6ms 1us 1us 36us 1us
# Rows sent 2 40.41k 1 1 1 1 0 1
# Rows examine 55 50.35M 1000 1.52k 1.25k 1.46k 159.63 1.20k
# Query size 9 1.61M 38 41 40.88 40.45 0.60 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 = 1065\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: 1561
# filtered: 10.00
# Extra: Using where
# Query 2: 2.38k QPS, 0.22x concurrency, ID 0xFBC5564AE716EAE82F20BFB45F6C37E7 at byte 12740740
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:36 to 2023-11-25T07:06:43
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 34 159332
# Exec time 11 15s 41us 10ms 91us 131us 161us 66us
# Lock time 40 175ms 0 5ms 1us 1us 23us 1us
# Rows sent 9 155.60k 1 1 1 1 0 1
# Rows examine 0 155.60k 1 1 1 1 0 1
# Query size 28 4.86M 31 33 31.96 31.70 0.42 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 = 11\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 3: 7.16 QPS, 0.13x concurrency, ID 0xA3401CA3ABCC04C3AB221DB8AD5CBF26 at byte 98289292
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:43
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 487
# Exec time 7 9s 5ms 55ms 19ms 34ms 9ms 17ms
# Lock time 0 390us 0 10us 0 1us 0 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 4 4.07M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 46.61k 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 >= 1704002400 AND end_at <= 1704063600\G
# Converted for EXPLAIN
# EXPLAIN
select slot = slot - 1 from reservation_slots where start_at >= 1704002400 AND end_at <= 1704063600\G
# Query 4: 7.18 QPS, 0.11x concurrency, ID 0x7F9C0C0BA9473953B723EE16C08655F1 at byte 98178121
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:05:35 to 2023-11-25T07:06:43
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 488
# Exec time 6 8s 5ms 47ms 16ms 28ms 7ms 14ms
# Lock time 0 519us 0 48us 1us 1us 2us 1us
# Rows sent 0 4.70k 1 21 9.87 18.53 5.79 9.83
# Rows examine 4 4.08M 8.55k 8.55k 8.55k 8.55k 0 8.55k
# Query size 0 45.75k 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 >= 1704002400 AND end_at <= 1704063600 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=1700895935819;before=1700896015826
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250705
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700895935823;before=1700896011855
pprof