saza-ku
commented
1 year ago isucon1
alp
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 6271 | GET | / | 0.004 | 0.068 | 63.224 | 0.010 | 0.028 |
| 6145 | GET | /posts/.+ | 0.004 | 0.044 | 42.940 | 0.007 | 0.024 |
| 1441 | GET | /@.+ | 0.004 | 0.068 | 23.368 | 0.016 | 0.040 |
| 1280 | GET | /posts | 0.004 | 0.060 | 23.052 | 0.018 | 0.036 |
| 4497 | POST | /login | 0.000 | 0.032 | 18.540 | 0.004 | 0.016 |
| 1214 | POST | / | 0.004 | 0.048 | 13.696 | 0.011 | 0.036 |
| 72035 | GET | /image/.+ | 0.000 | 0.039 | 10.915 | 0.000 | 0.004 |
| 1113 | POST | /register | 0.004 | 0.028 | 6.036 | 0.005 | 0.020 |
| 1113 | GET | /admin/banned | 0.004 | 0.032 | 4.692 | 0.004 | 0.016 |
| 994 | POST | /comment | 0.004 | 0.024 | 4.544 | 0.005 | 0.016 |
| 784 | GET | /login | 0.000 | 0.020 | 2.856 | 0.004 | 0.016 |
| 392 | GET | /logout | 0.004 | 0.024 | 1.680 | 0.004 | 0.016 |
| 6828 | GET | /favicon.ico | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 6828 | GET | /js/timeago.min.js | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 6828 | GET | /js/main.js | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 6828 | GET | /css/style.css | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
slow query
Count: 7559 Time=0.00s (4s) Lock=0.00s (0s) Rows=37.6 (284164), 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: 7559 Time=0.00s (3s) Lock=0.00s (0s) Rows=4.0 (30006), 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: 10742 Time=0.00s (1s) Lock=0.00s (0s) Rows=1.0 (10742), isuconp[isuconp]@localhost
SELECT * FROM `users` WHERE `id` = N
Count: 6145 Time=0.00s (1s) Lock=0.00s (0s) Rows=8.6 (52693), isuconp[isuconp]@localhost
SELECT * FROM comments WHERE post_id IN (N) ORDER BY `created_at` DESC
Count: 6271 Time=0.00s (1s) Lock=0.00s (0s) Rows=20.0 (125420), 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: 6145 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.9 (5443), isuconp[isuconp]@localhost
SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (N) GROUP BY `post_id`
Count: 4664 Time=0.00s (1s) Lock=0.00s (0s) Rows=19.8 (92485), 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)
Count: 6145 Time=0.00s (1s) Lock=0.00s (0s) Rows=1.0 (6145), isuconp[isuconp]@localhost
SELECT * FROM `not_banned_posts_without_imgdata` WHERE `id` = N
Count: 4497 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.9 (4105), isuconp[isuconp]@localhost
SELECT * FROM users WHERE account_name = 'S' AND del_flg = N
Count: 1280 Time=0.00s (0s) Lock=0.00s (0s) Rows=20.0 (25600), isuconp[isuconp]@localhost
SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `not_banned_posts_without_imgdata` WHERE `created_at` <= 'S' ORDER BY `created_at` DESC LIMIT N
explain
Reading from STDIN ...
# 5.3s user time, 50ms system time, 37.12M rss, 51.31M vsz
# Current date: Fri Nov 10 14:34:01 2023
# Hostname: ip-172-31-22-189
# Files: STDIN
# Overall: 85.39k total, 24 unique, 1.11k QPS, 0.36x concurrency _________
# Time range: 2023-11-10T05:32:39 to 2023-11-10T05:33:56
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 27s 25us 61ms 320us 925us 434us 194us
# Lock time 169ms 0 3ms 1us 3us 12us 1us
# Rows sent 1.27M 0 237 15.58 92.72 37.43 0.99
# Rows examine 2.42M 0 474 29.74 183.58 66.87 5.75
# Query size 11.23M 16 1.26k 137.89 223.14 147.25 97.36
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x1ADC9E80BE48F05D4A5F6D65... 7.9550 29.1% 15137 0.0005 0.00 SELECT comments
# 2 0x395AE969FAFDA16C400891B7... 5.4690 20.0% 15137 0.0004 0.00 SELECT users
# 3 0x9B36FBB6889AD40E391C181F... 4.8042 17.5% 15137 0.0003 0.00 SELECT comments
# 4 0x396201721CD58410E070DA94... 1.6896 6.2% 10742 0.0002 0.00 SELECT users
# MISC 0xMISC 7.4600 27.2% 29242 0.0003 0.0 <20 ITEMS>
# Query 1: 252.28 QPS, 0.13x concurrency, ID 0x1ADC9E80BE48F05D4A5F6D6502F7A387 at byte 846
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:32:39 to 2023-11-10T05:33:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 17 15137
# Exec time 29 8s 92us 61ms 525us 2ms 789us 301us
# Lock time 16 27ms 0 367us 1us 1us 5us 1us
# Rows sent 35 466.93k 0 237 31.59 192.76 59.40 5.75
# Rows examine 35 882.40k 0 474 59.69 381.65 120.07 5.75
# Query size 18 2.07M 70 207 143.23 202.40 60.53 174.84
# 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 (10000, 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: 205
# filtered: 100.00
# Extra: Using index condition; Using filesort
# Query 2: 252.28 QPS, 0.09x concurrency, ID 0x395AE969FAFDA16C400891B7C96D9565 at byte 166023
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:32:39 to 2023-11-10T05:33:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 17 15137
# Exec time 19 5s 62us 10ms 361us 1ms 417us 194us
# Lock time 18 31ms 0 3ms 2us 1us 24us 1us
# Rows sent 44 582.79k 1 232 39.43 192.76 54.72 19.46
# Rows examine 23 582.79k 1 232 39.43 192.76 54.72 19.46
# Query size 31 3.49M 36 1.26k 242.08 1.04k 302.60 124.25
# 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
# EXPLAIN
SELECT * FROM users WHERE id IN (562, 815, 395, 112, 792, 149, 89, 876, 517, 455, 945, 618, 304, 775, 878, 161, 963, 649, 92, 544, 41, 296, 804, 659, 503, 479, 262, 787, 486, 840, 599, 979, 82, 471, 401, 854, 961, 701, 652, 178, 214, 263, 946, 502, 676, 891, 505, 596, 119, 548, 916, 801, 972, 234, 969, 573, 646, 47, 973, 686, 229, 368, 440, 594, 129, 328, 363, 838, 266, 748, 308, 718, 516, 580, 27, 215, 32, 481, 82, 715, 357, 410, 248, 286, 868, 483, 893, 533, 61, 342, 189, 112, 362, 230, 142, 93, 455, 525, 286, 222, 697, 362, 859, 303, 896, 24, 311, 355, 736, 784, 796, 853, 648, 273, 925, 532, 603, 588, 455, 844, 999, 767, 974, 549, 395, 225, 778, 57, 8, 714, 409, 342, 241, 75, 62, 313, 395, 75, 37, 500, 688, 250, 542, 362, 442, 342, 117, 943, 184, 836, 729, 423, 6, 165, 741, 386, 86, 575, 183, 744, 624, 19, 406, 559, 89, 896, 598, 487, 376, 490, 857, 178, 396, 665, 257, 469, 961, 750, 631, 727, 175, 136, 91, 247, 748, 829, 798)\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: users
# partitions: NULL
# type: range
# possible_keys: PRIMARY
# key: PRIMARY
# key_len: 4
# ref: NULL
# rows: 170
# filtered: 100.00
# Extra: Using where
# Query 3: 252.28 QPS, 0.08x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 9874011
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:32:39 to 2023-11-10T05:33:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 17 15137
# Exec time 17 5s 75us 4ms 317us 690us 240us 273us
# Lock time 15 26ms 0 598us 1us 1us 7us 1us
# Rows sent 3 48.46k 0 20 3.28 19.46 5.84 0.99
# Rows examine 18 466.93k 0 237 31.59 192.76 59.40 5.75
# Query size 21 2.43M 95 232 168.23 223.14 58.61 192.76
# 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 (11816, 11817, 11818, 11819, 11820, 11806, 11807, 11808, 11809, 11810, 11811, 11812, 11813, 11814, 11815, 11795, 11796, 11797, 11798, 11799) 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: 24
# filtered: 100.00
# Extra: Using where; Using index
# Query 4: 179.03 QPS, 0.03x concurrency, ID 0x396201721CD58410E070DA9421CA8C8D at byte 15565152
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:32:39 to 2023-11-10T05:33:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 10742
# Exec time 6 2s 54us 4ms 157us 348us 143us 113us
# Lock time 13 22ms 0 710us 2us 4us 8us 1us
# Rows sent 0 10.49k 1 1 1 1 0 1
# Rows examine 0 10.49k 1 1 1 1 0 1
# Query size 3 398.81k 37 39 38.02 38.53 0.56 36.69
# 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
# EXPLAIN
SELECT * FROM `users` WHERE `id` = 4506\G
# *************************** 1. row ***************************
# id: 1
# select_type: SIMPLE
# table: users
# partitions: NULL
# type: const
# possible_keys: PRIMARY
# key: PRIMARY
# key_len: 4
# ref: const
# rows: 1
# filtered: 100.00
# Extra: NULL
netdata
http://localhost:19991/#menu_apps_submenu_cpu;after=1699594358995;before=1699594435099
pprof
go tool pprof -http=0.0.0.0:1080 http://isucon1/pprof/11100232
136266
https://github.com/Saza-ku/private-isu-2023/pull/92