saza-ku
commented
1 year ago isucon1
alp
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 6977 | GET | / | 0.004 | 0.060 | 49.040 | 0.007 | 0.020 |
| 5567 | GET | /posts/.+ | 0.004 | 0.080 | 26.597 | 0.005 | 0.016 |
| 1930 | GET | /@.+ | 0.004 | 0.040 | 20.216 | 0.010 | 0.028 |
| 1192 | POST | / | 0.004 | 0.072 | 16.557 | 0.014 | 0.064 |
| 1816 | POST | /register | 0.004 | 0.112 | 14.112 | 0.008 | 0.020 |
| 1608 | POST | /comment | 0.004 | 0.060 | 12.456 | 0.008 | 0.020 |
| 4982 | POST | /login | 0.000 | 0.084 | 10.024 | 0.002 | 0.012 |
| 510 | GET | /posts | 0.004 | 0.048 | 6.576 | 0.013 | 0.032 |
| 4230 | GET | /favicon.ico | 0.000 | 0.016 | 4.112 | 0.001 | 0.008 |
| 4230 | GET | /js/main.js | 0.000 | 0.012 | 3.676 | 0.001 | 0.008 |
| 4230 | GET | /css/style.css | 0.000 | 0.020 | 3.492 | 0.001 | 0.008 |
| 4230 | GET | /js/timeago.min.js | 0.000 | 0.016 | 3.489 | 0.001 | 0.008 |
| 1816 | GET | /admin/banned | 0.000 | 0.017 | 3.485 | 0.002 | 0.008 |
| 244 | GET | /login | 0.000 | 0.012 | 0.488 | 0.002 | 0.012 |
| 122 | GET | /logout | 0.000 | 0.024 | 0.268 | 0.002 | 0.016 |
| 28422 | GET | /image/.+ | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
slow query
Count: 1816 Time=0.01s (9s) Lock=0.00s (0s) Rows=0.0 (0), isuconp[isuconp]@localhost
INSERT INTO `users` (`account_name`, `passhash`) VALUES ('S','S')
Count: 1608 Time=0.01s (8s) Lock=0.00s (0s) Rows=0.0 (0), isuconp[isuconp]@localhost
INSERT INTO `comments` (`post_id`, `user_id`, `comment`) VALUES (N,N,'S')
Count: 7498 Time=0.00s (3s) Lock=0.00s (0s) Rows=18.0 (134912), isuconp[isuconp]@localhost
SELECT * FROM comments WHERE post_id IN (N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N) ORDER BY `created_at` DESC
Count: 596 Time=0.01s (2s) Lock=0.00s (0s) Rows=0.0 (0), isuconp[isuconp]@localhost
INSERT INTO `not_banned_posts_without_imgdata` (`user_id`, `mime`, `body`) VALUES (N,'S','S')
Count: 7498 Time=0.00s (2s) Lock=0.00s (0s) Rows=2.2 (16224), isuconp[isuconp]@localhost
SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N) GROUP BY `post_id`
Count: 14982 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.0 (14982), isuconp[isuconp]@localhost
SELECT * FROM `users` WHERE `id` = N
Count: 6977 Time=0.00s (1s) Lock=0.00s (0s) Rows=20.0 (139540), isuconp[isuconp]@localhost
SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `not_banned_posts_without_imgdata` ORDER BY `created_at` DESC LIMIT N
Count: 5568 Time=0.00s (1s) Lock=0.00s (0s) Rows=8.6 (47659), isuconp[isuconp]@localhost
SELECT * FROM comments WHERE post_id IN (N) ORDER BY `created_at` DESC
Count: 5568 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.9 (4894), isuconp[isuconp]@localhost
SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (N) GROUP BY `post_id`
Count: 3927 Time=0.00s (0s) Lock=0.00s (0s) Rows=19.9 (78150), isuconp[isuconp]@localhost
SELECT * FROM users WHERE id IN (N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N)
explain
Reading from STDIN ...
# 7.9s user time, 110ms system time, 37.93M rss, 50.92M vsz
# Current date: Sat Oct 28 01:49:50 2023
# Hostname: private-isu
# Files: STDIN
# Overall: 101.93k total, 23 unique, 1.32k QPS, 0.58x concurrency ________
# Time range: 2023-10-27T16:48:25 to 2023-10-27T16:49:42
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 45s 1us 109ms 441us 1ms 1ms 176us
# Lock time 181ms 0 3ms 1us 1us 13us 1us
# Rows sent 1.09M 0 245 11.24 46.83 28.34 0.99
# Rows examine 2.11M 0 490 21.70 118.34 51.41 0.99
# Query size 11.58M 17 1.30k 119.17 223.14 118.33 88.31
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x26489ECBE26887E480CA8067... 9.4909 21.1% 1816 0.0052 0.00 INSERT users
# 2 0x9F2038550F51B0A3AB05CA52... 8.3051 18.4% 1608 0.0052 0.00 INSERT comments
# 3 0x1ADC9E80BE48F05D4A5F6D65... 6.4892 14.4% 14984 0.0004 0.00 SELECT comments
# 4 0x9B36FBB6889AD40E391C181F... 4.7508 10.6% 14984 0.0003 0.00 SELECT comments
# MISC 0xMISC 15.9851 35.5% 68536 0.0002 0.0 <19 ITEMS>
# Query 1: 30.27 QPS, 0.16x concurrency, ID 0x26489ECBE26887E480CA8067F971EA04 at byte 30155370
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-10-27T16:48:25 to 2023-10-27T16:49:25
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 1 1816
# Exec time 21 9s 2ms 109ms 5ms 7ms 4ms 5ms
# Lock time 1 3ms 0 25us 1us 1us 1us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 3 383.06k 216 216 216 216 0 216
# String:
# Hosts localhost
# Users isuconp
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ################################################################
# 10ms #
# 100ms #
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'users'\G
# SHOW CREATE TABLE `users`\G
INSERT INTO `users` (`account_name`, `passhash`) VALUES ('eLawNO2px0okXL3Ww4eVmVqoG','e0e8a291918dc9fa79777fc6a8a9d68a15420dd04d81e438e55a42d38999ac1b939e58fdfdf7dac81f2831a9767b31700b8dca153470e4019b95c6fa1bbc7141')\G
# Query 2: 26.80 QPS, 0.14x concurrency, ID 0x9F2038550F51B0A3AB05CA526E3FEDDC at byte 24422759
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-10-27T16:48:25 to 2023-10-27T16:49:25
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 1 1608
# Exec time 18 8s 2ms 59ms 5ms 7ms 2ms 5ms
# Lock time 1 3ms 1us 74us 1us 1us 2us 1us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 1 216.03k 85 208 137.57 174.84 24.58 130.47
# String:
# Hosts localhost
# Users isuconp
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ################################################################
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'comments'\G
# SHOW CREATE TABLE `comments`\G
INSERT INTO `comments` (`post_id`, `user_id`, `comment`) VALUES (13253,802,'お(o|o)┘め└(o|o)で(o|o)と└(o|o)う└(o|o)┘')\G
# Query 3: 245.64 QPS, 0.11x concurrency, ID 0x1ADC9E80BE48F05D4A5F6D6502F7A387 at byte 52499
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-10-27T16:48:25 to 2023-10-27T16:49:26
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 14984
# Exec time 14 6s 99us 34ms 433us 1ms 540us 301us
# Lock time 16 31ms 0 3ms 2us 1us 27us 1us
# Rows sent 32 367.31k 0 245 25.10 143.84 49.01 1.96
# Rows examine 31 688.08k 0 490 47.02 284.79 99.06 3.89
# Query size 18 2.09M 70 207 146.30 202.40 60.10 183.58
# String:
# Hosts localhost
# Users isuconp
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms #####
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'comments'\G
# SHOW CREATE TABLE `comments`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM comments WHERE post_id IN (13224, 9999, 9998, 9997, 9996, 9995, 9994, 9993, 9991, 9990, 9989, 9988, 9987, 9986, 9985, 9983, 9982, 9981, 9980, 9979) ORDER BY `created_at` DESC\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: comments
# partitions: NULL
# type: range
# possible_keys: comments_post_id_index
# key: comments_post_id_index
# key_len: 4
# ref: NULL
# rows: 202
# filtered: 100.00
# Extra: Using index condition; Using filesort
# Query 4: 245.64 QPS, 0.08x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 49343
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-10-27T16:48:25 to 2023-10-27T16:49:26
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 14984
# Exec time 10 5s 96us 28ms 317us 568us 373us 273us
# Lock time 17 31ms 0 1ms 2us 1us 16us 1us
# Rows sent 3 39.56k 0 20 2.70 13.83 4.74 0.99
# Rows examine 17 367.32k 0 245 25.10 143.84 49.01 1.96
# Query size 21 2.45M 95 232 171.30 223.14 58.27 202.40
# String:
# Hosts localhost
# Users isuconp
# Query_time distribution
# 1us
# 10us #
# 100us ################################################################
# 1ms #
# 10ms #
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS LIKE 'comments'\G
# SHOW CREATE TABLE `comments`\G
# EXPLAIN
SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (9845, 7166, 4023, 3381, 2578, 1914, 1476) GROUP BY `post_id`\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: comments
# partitions: NULL
# type: range
# possible_keys: comments_post_id_index
# key: comments_post_id_index
# key_len: 4
# ref: NULL
# rows: 73
# filtered: 100.00
# Extra: Using where; Using index
netdata
http://localhost:19991/#menu_apps_submenu_cpu;after=1698425305034;before=1698425381277
pprof
go tool pprof -http=0.0.0.0:1080 http://isucon1/pprof/10280148
85754
https://github.com/Saza-ku/private-isu-2023/pull/57