saza-ku
commented
8 months ago isucon3
alp
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
slow query
Count: 61862 Time=0.00s (46s) Lock=0.00s (0s) Rows=1.0 (61862), isucon[isucon]@isucon1
SELECT * FROM themes WHERE user_id = N
Count: 288207 Time=0.00s (21s) Lock=0.00s (0s) Rows=1.0 (288207), isucon[isucon]@isucon1
SELECT * FROM tags WHERE id = N
Count: 66490 Time=0.00s (16s) Lock=0.00s (0s) Rows=0.9 (62152), isucon[isucon]@isucon1
SELECT icon_path FROM icons WHERE user_id = N
Count: 60107 Time=0.00s (8s) Lock=0.00s (0s) Rows=4.8 (288222), isucon[isucon]@isucon1
SELECT * FROM livestream_tags WHERE livestream_id = N
Count: 234 Time=0.02s (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: 61401 Time=0.00s (5s) Lock=0.00s (0s) Rows=1.0 (61401), isucon[isucon]@isucon1
SELECT * FROM users WHERE id = N
Count: 233 Time=0.02s (4s) Lock=0.00s (0s) Rows=1.2 (287), isucon[isucon]@isucon1
SELECT * FROM livestreams WHERE user_id = N
Count: 235 Time=0.02s (4s) Lock=0.00s (0s) Rows=9.4 (2217), isucon[isucon]@isucon1
SELECT * FROM reservation_slots WHERE start_at >= N AND end_at <= N FOR UPDATE
Count: 6811 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@isucon1
COMMIT
Count: 471 Time=0.00s (0s) Lock=0.00s (0s) Rows=7.7 (3620), isucon[isucon]@isucon1
SELECT * FROM livecomments WHERE livestream_id = N ORDER BY created_at DESC
explain
Reading from STDIN ...
# 35.2s user time, 110ms system time, 37.75M rss, 52.11M vsz
# Current date: Sat Nov 25 07:18:08 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 584.03k total, 65 unique, 6.21k QPS, 1.29x concurrency ________
# Time range: 2023-11-25T07:16:08 to 2023-11-25T07:17:42
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 122s 1us 54ms 208us 626us 907us 76us
# Lock time 510ms 0 3ms 0 1us 13us 1us
# Rows sent 1.10M 0 7.32k 1.97 4.96 24.87 0.99
# Rows examine 106.76M 0 11.54k 191.68 1.26k 496.39 0.99
# Query size 21.24M 6 447 38.14 54.21 16.55 31.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================ ============= ====== ====== ===== ====
# 1 0x38BC86A45F31C6B1EE32467... 46.6744 38.4% 61863 0.0008 0.00 SELECT themes
# 2 0xFBC5564AE716EAE82F20BFB... 22.1122 18.2% 288207 0.0001 0.00 SELECT tags
# 3 0xB4FC1F99A422ACB1A54E6E2... 16.5563 13.6% 66491 0.0002 0.00 SELECT icons
# 4 0xF7144185D9A142A426A36DC... 8.5381 7.0% 60107 0.0001 0.00 SELECT livestream_tags
# MISC 0xMISC 27.7220 22.8% 107359 0.0003 0.0 <61 ITEMS>
# Query 1: 658.12 QPS, 0.50x concurrency, ID 0x38BC86A45F31C6B1EE324671506C898A at byte 50394735
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:16:08 to 2023-11-25T07:17:42
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 10 61863
# Exec time 38 47s 238us 13ms 754us 2ms 537us 596us
# Lock time 10 54ms 0 2ms 0 1us 10us 1us
# Rows sent 5 60.41k 1 1 1 1 0 1
# Rows examine 72 77.82M 1000 1.42k 1.29k 1.39k 108.06 1.26k
# Query size 11 2.42M 38 41 40.96 40.45 0.38 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 = 1163\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: 1451
# filtered: 10.00
# Extra: Using where
# Query 2: 4.30k QPS, 0.33x concurrency, ID 0xFBC5564AE716EAE82F20BFB45F6C37E7 at byte 98190764
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:16:08 to 2023-11-25T07:17:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 49 288207
# Exec time 18 22s 41us 15ms 76us 89us 110us 66us
# Lock time 48 249ms 0 3ms 0 1us 11us 1us
# Rows sent 24 281.45k 1 1 1 1 0 1
# Rows examine 0 281.45k 1 1 1 1 0 1
# Query size 41 8.78M 31 33 31.96 31.70 0.44 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 = 41\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: 707.35 QPS, 0.18x concurrency, ID 0xB4FC1F99A422ACB1A54E6E2F01B84879 at byte 140994795
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:16:08 to 2023-11-25T07:17:42
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 11 66491
# Exec time 13 17s 46us 12ms 248us 424us 274us 204us
# Lock time 11 61ms 0 3ms 0 1us 14us 1us
# Rows sent 5 60.70k 0 1 0.93 0.99 0.25 0.99
# Rows examine 18 19.34M 0 444 305.00 420.77 105.96 313.99
# Query size 14 3.04M 45 48 47.94 46.83 0.17 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 = 1231\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: 444
# filtered: 10.00
# Extra: Using where
# Query 4: 897.12 QPS, 0.13x concurrency, ID 0xF7144185D9A142A426A36DC55C1D2623 at byte 49657698
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:16:08 to 2023-11-25T07:17:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 10 60107
# Exec time 7 9s 61us 53ms 142us 152us 632us 108us
# Lock time 10 55ms 0 2ms 0 1us 12us 1us
# Rows sent 24 281.47k 0 11 4.80 4.96 0.87 4.96
# Rows examine 0 281.47k 0 11 4.80 4.96 0.87 4.96
# Query size 15 3.21M 53 56 55.99 54.21 0.06 54.21
# 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
# EXPLAIN
SELECT * FROM livestream_tags WHERE livestream_id = 7612\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: livestream_tags
# partitions: NULL
# type: ref
# possible_keys: livestream_id
# key: livestream_id
# key_len: 8
# ref: const
# rows: 5
# filtered: 100.00
# Extra: NULL
netdata
http://localhost:19993/#menu_services;after=1700896568262;before=1700896648270
pprof
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250716
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700896568245;before=1700896644304
pprof