Open saza-ku opened 8 months ago
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 33416 Time=0.00s (55s) Lock=0.00s (0s) Rows=0.2 (6100), 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: 24247 Time=0.00s (37s) Lock=0.00s (0s) Rows=0.5 (12276), 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: 40792 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: 553 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: 1106 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.5 (553), 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: 91915 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
#
Count: 553 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: 553 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@isucon1
commit
Count: 553 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (553), isudns[isudns]@isucon1
select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'
Count: 1107 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:41:27 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 195.36k total, 21 unique, 2.12k QPS, 1.12x concurrency ________
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:41:24
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 103s 1us 90ms 529us 2ms 857us 89us
# Lock time 154ms 0 5ms 0 1us 19us 1us
# Rows sent 19.03k 0 1 0.10 0.99 0.30 0
# Rows examine 88.54M 0 1.79k 475.21 1.69k 707.07 0
# Query size 15.38M 5 217 82.54 151.03 48.75 112.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x42EF7D7D98FBCC9723BF896E... 55.7174 53.9% 33416 0.0017 0.00 SELECT records
# 2 0x3D83BC87F3B3A00D571FFC81... 37.5388 36.3% 24247 0.0015 0.00 SELECT records
# 3 0x22279D81D51006139E0C7640... 4.5526 4.4% 40792 0.0001 0.00 SELECT domains domainmetadata
# 4 0x859BBB7E9D760686137A9444... 2.0439 2.0% 553 0.0037 0.00 DELETE records
# MISC 0xMISC 3.5377 3.4% 96349 0.0000 0.0 <17 ITEMS>
# Query 1: 498.75 QPS, 0.83x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 25002114
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:40:59
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 17 33416
# Exec time 53 56s 698us 90ms 2ms 2ms 920us 2ms
# Lock time 26 41ms 0 1ms 1us 1us 8us 1us
# Rows sent 31 5.96k 0 1 0.18 0.99 0.38 0
# Rows examine 56 49.85M 1.25k 1.79k 1.53k 1.69k 149.32 1.46k
# Query size 29 4.52M 129 217 141.80 158.58 11.81 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='l0t8g2anljfautl8qe0.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='l0t8g2anljfautl8qe0.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.
# Query 2: 361.90 QPS, 0.56x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 38603131
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:40:59
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 24247
# Exec time 36 38s 655us 10ms 2ms 2ms 429us 1ms
# Lock time 18 28ms 0 91us 1us 1us 0 1us
# Rows sent 62 11.99k 0 1 0.51 0.99 0.50 0.99
# Rows examine 40 36.22M 1.25k 1.79k 1.53k 1.69k 149.70 1.46k
# Query size 20 3.13M 126 216 135.55 151.03 11.16 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='amaeda0.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='amaeda0.u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.
# Query 3: 608.84 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 53269933
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:40:59
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 20 40792
# Exec time 4 5s 71us 4ms 111us 125us 86us 98us
# Lock time 40 62ms 0 3ms 1us 1us 17us 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.43M 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.51 QPS, 0.03x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 52155726
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:53 to 2023-11-25T07:40:58
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 553
# Exec time 1 2s 2ms 9ms 4ms 5ms 734us 4ms
# Lock time 13 21ms 0 5ms 38us 1us 319us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 840.29k 1.25k 1.79k 1.52k 1.69k 157.27 1.46k
# Query size 0 46.19k 78 93 85.52 88.31 3.38 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='itorika0.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN
select * from records where domain_id=4 and name='itorika0.u.isucon.dev' and type='A'\G
http://localhost:19992/#menu_services;after=1700897992809;before=1700898072819
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250739
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 16266 Time=0.00s (12s) Lock=0.00s (0s) Rows=1.0 (16266), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id = N
Count: 36285 Time=0.00s (8s) Lock=0.00s (0s) Rows=0.9 (32946), isucon[isucon]@isucon1
SELECT icon_path FROM icons WHERE user_id = N
Count: 650 Time=0.01s (7s) Lock=0.00s (0s) Rows=2.4 (1551), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Count: 54324 Time=0.00s (5s) Lock=0.00s (0s) Rows=1.0 (54324), isucon[isucon]@isucon1
SELECT * FROM tags WHERE id = N
Count: 469 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: 470 Time=0.01s (5s) Lock=0.00s (0s) Rows=9.9 (4635), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 2071 Time=0.00s (3s) Lock=0.00s (0s) Rows=9.3 (19297), isucon[isucon]@isucon1
SELECT * FROM reactions WHERE livestream_id = N ORDER BY created_at DESC
Count: 20659 Time=0.00s (3s) Lock=0.00s (0s) Rows=1.0 (20658), isucon[isucon]@isucon1
SELECT * FROM users WHERE name = 'S'
Count: 10968 Time=0.00s (2s) Lock=0.00s (0s) Rows=5.0 (54328), isucon[isucon]@isucon1
SELECT * FROM livestream_tags WHERE livestream_id = N
Count: 15688 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.0 (15688), isucon[isucon]@isucon1
SELECT * FROM users WHERE id = N
Reading from STDIN ...
# 18s user time, 70ms system time, 38.00M rss, 52.48M vsz
# Current date: Sat Nov 25 07:41:33 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 286.44k total, 70 unique, 3.11k QPS, 0.83x concurrency ________
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:41:24
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 77s 1us 152ms 267us 725us 1ms 80us
# Lock time 248ms 0 3ms 0 1us 14us 1us
# Rows sent 2.55M 0 7.78k 9.32 4.96 122.60 0.99
# Rows examine 58.14M 0 12.84k 212.85 1.26k 737.46 0.99
# Query size 12.29M 6 902 45.00 97.36 53.24 34.95
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0x38BC86A45F31C6B1EE32467... 12.1378 15.9% 16266 0.0007 0.00 SELECT themes
# 2 0xB4FC1F99A422ACB1A54E6E2... 9.0062 11.8% 36285 0.0002 0.00 SELECT icons
# 3 0x9EAD6C0CE525E3693EE27FF... 7.5855 9.9% 650 0.0117 0.00 SELECT livestreams
# 4 0xFBC5564AE716EAE82F20BFB... 5.6366 7.4% 54324 0.0001 0.00 SELECT tags
# MISC 0xMISC 42.1904 55.1% 178916 0.0002 0.0 <66 ITEMS>
# Query 1: 246.45 QPS, 0.18x concurrency, ID 0x38BC86A45F31C6B1EE324671506C898A at byte 17738084
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:40:58
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 5 16266
# Exec time 15 12s 239us 17ms 746us 2ms 638us 568us
# Lock time 6 16ms 0 635us 1us 1us 7us 1us
# Rows sent 0 15.88k 1 1 1 1 0 1
# Rows examine 34 19.99M 1000 1.52k 1.26k 1.46k 152.33 1.26k
# Query size 5 651.20k 38 41 40.99 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 = 1013\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: 1553
# filtered: 10.00
# Extra: Using where
# Query 2: 549.77 QPS, 0.14x concurrency, ID 0xB4FC1F99A422ACB1A54E6E2F01B84879 at byte 63978171
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:40:58
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 36285
# Exec time 11 9s 49us 12ms 248us 541us 311us 194us
# Lock time 16 40ms 0 1ms 1us 1us 12us 1us
# Rows sent 1 32.17k 0 1 0.91 0.99 0.29 0.99
# Rows examine 17 9.90M 0 545 286.14 511.45 150.42 284.79
# Query size 13 1.66M 45 48 47.92 46.83 0.21 46.83
# 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
SELECT icon_path FROM icons WHERE user_id = 1025\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: 545
# filtered: 10.00
# Extra: Using where
# Query 3: 9.85 QPS, 0.11x concurrency, ID 0x9EAD6C0CE525E3693EE27FFC9AAF05A3 at byte 44458666
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:52 to 2023-11-25T07:40:58
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 650
# Exec time 9 8s 4ms 45ms 12ms 22ms 6ms 10ms
# Lock time 0 608us 0 15us 0 1us 0 1us
# Rows sent 0 1.51k 0 21 2.39 6.98 2.81 1.96
# Rows examine 8 4.81M 7.32k 7.78k 7.58k 7.68k 169.96 7.31k
# Query size 0 29.19k 43 46 45.98 44.60 0.17 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 = 1157\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: 7829
# filtered: 10.00
# Extra: Using where
# Query 4: 835.75 QPS, 0.09x concurrency, ID 0xFBC5564AE716EAE82F20BFB45F6C37E7 at byte 14300863
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:39:53 to 2023-11-25T07:40:58
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 18 54324
# Exec time 7 6s 42us 11ms 103us 204us 199us 69us
# Lock time 24 60ms 0 2ms 1us 1us 13us 1us
# Rows sent 2 53.05k 1 1 1 1 0 1
# Rows examine 0 53.05k 1 1 1 1 0 1
# Query size 13 1.65M 31 33 31.94 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 = 12\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
http://localhost:19993/#menu_services;after=1700897992807;before=1700898072814
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250739
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700897992805;before=1700898068776
pprof