saza-ku
commented
1 year ago isucon1
alp
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 9094 | GET | / | 0.004 | 0.108 | 56.880 | 0.006 | 0.020 |
| 5919 | GET | /posts/.+ | 0.000 | 0.028 | 25.192 | 0.004 | 0.016 |
| 2378 | GET | /@.+ | 0.004 | 0.088 | 22.772 | 0.010 | 0.024 |
| 1364 | POST | / | 0.000 | 0.076 | 15.084 | 0.011 | 0.060 |
| 6337 | POST | /login | 0.004 | 0.036 | 12.300 | 0.002 | 0.012 |
| 550 | GET | /posts | 0.004 | 0.056 | 6.704 | 0.012 | 0.036 |
| 2573 | POST | /register | 0.004 | 0.036 | 5.680 | 0.002 | 0.012 |
| 2066 | POST | /comment | 0.004 | 0.040 | 4.852 | 0.002 | 0.012 |
| 2573 | GET | /admin/banned | 0.000 | 0.020 | 4.644 | 0.002 | 0.012 |
| 3999 | GET | /favicon.ico | 0.000 | 0.020 | 4.328 | 0.001 | 0.008 |
| 3999 | GET | /js/timeago.min.js | 0.004 | 0.016 | 4.132 | 0.001 | 0.008 |
| 3999 | GET | /js/main.js | 0.000 | 0.020 | 3.872 | 0.001 | 0.008 |
| 3999 | GET | /css/style.css | 0.000 | 0.016 | 3.576 | 0.001 | 0.008 |
| 222 | GET | /login | 0.000 | 0.016 | 0.464 | 0.002 | 0.008 |
| 111 | GET | /logout | 0.000 | 0.008 | 0.212 | 0.002 | 0.008 |
| 28364 | GET | /image/.+ | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
slow query
Count: 9659 Time=0.00s (4s) Lock=0.00s (0s) Rows=15.6 (150994), 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: 9659 Time=0.00s (3s) Lock=0.00s (0s) Rows=2.1 (20109), 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: 19505 Time=0.00s (2s) Lock=0.00s (0s) Rows=1.0 (19505), isuconp[isuconp]@localhost
SELECT * FROM `users` WHERE `id` = N
Count: 9094 Time=0.00s (1s) Lock=0.00s (0s) Rows=20.0 (181880), 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: 5919 Time=0.00s (1s) Lock=0.00s (0s) Rows=8.4 (49581), isuconp[isuconp]@localhost
SELECT * FROM comments WHERE post_id IN (N) ORDER BY `created_at` DESC
Count: 6337 Time=0.00s (1s) Lock=0.00s (0s) Rows=1.0 (6226), isuconp[isuconp]@localhost
SELECT * FROM users WHERE account_name = 'S' AND del_flg = N
Count: 5919 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.9 (5179), isuconp[isuconp]@localhost
SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (N) GROUP BY `post_id`
Count: 5919 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (5919), isuconp[isuconp]@localhost
SELECT * FROM `not_banned_posts_without_imgdata` WHERE `id` = N
Count: 3911 Time=0.00s (0s) Lock=0.00s (0s) Rows=19.7 (77094), 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: 3672 Time=0.00s (0s) Lock=0.00s (0s) Rows=20.8 (76396), 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, N)
explain
Reading from STDIN ...
# 9.7s user time, 90ms system time, 37.66M rss, 50.94M vsz
# Current date: Thu Nov 9 23:55:06 2023
# Hostname: private-isu
# Files: STDIN
# Overall: 121.88k total, 23 unique, 1.56k QPS, 0.35x concurrency ________
# Time range: 2023-11-09T14:53:38 to 2023-11-09T14:54:56
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 27s 1us 102ms 225us 515us 524us 159us
# Lock time 216ms 0 2ms 1us 1us 13us 1us
# Rows sent 1.31M 0 259 11.25 46.83 27.93 0.99
# Rows examine 2.50M 0 518 21.47 112.70 50.53 0.99
# Query size 14.25M 17 1.36k 122.58 223.14 116.76 97.36
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0x1ADC9E80BE48F05D4A5F6D65... 7.4887 27.2% 17940 0.0004 0.00 SELECT comments
# 2 0x9B36FBB6889AD40E391C181F... 4.9793 18.1% 17940 0.0003 0.00 SELECT comments
# 3 0x395AE969FAFDA16C400891B7... 4.6680 17.0% 17940 0.0003 0.00 SELECT users
# 4 0x396201721CD58410E070DA94... 2.6119 9.5% 19505 0.0001 0.00 SELECT users
# MISC 0xMISC 7.7407 28.2% 48556 0.0002 0.0 <19 ITEMS>
# Query 1: 294.10 QPS, 0.12x 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-09T14:53:38 to 2023-11-09T14:54:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 17940
# Exec time 27 7s 94us 102ms 417us 1ms 1ms 273us
# Lock time 15 34ms 0 1ms 1us 1us 12us 1us
# Rows sent 31 425.22k 0 259 24.27 130.47 48.42 1.96
# Rows examine 31 802.02k 0 518 45.78 271.23 97.72 3.89
# Query size 18 2.59M 70 207 151.65 202.40 59.31 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 /*!50100 PARTITIONS*/
SELECT * FROM comments WHERE post_id IN (9999, 9998, 9997, 9996, 9995, 9994, 9993, 9991, 9990, 9989, 9988, 9987, 9986, 9985, 9983, 9982, 9981, 9980, 9979, 9977) 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: 223
# filtered: 100.00
# Extra: Using index condition; Using filesort
# Query 2: 294.10 QPS, 0.08x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 17237861
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T14:53:38 to 2023-11-09T14:54:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 17940
# Exec time 18 5s 94us 9ms 277us 467us 248us 247us
# Lock time 15 33ms 0 725us 1us 1us 9us 1us
# Rows sent 3 47.79k 0 20 2.73 13.83 4.58 0.99
# Rows examine 16 425.23k 0 259 24.27 130.47 48.42 1.96
# Query size 21 3.02M 95 232 176.65 223.14 57.49 223.14
# 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 (9806, 9805, 9804, 9803, 9802, 9801, 9800, 9799, 9798, 9797, 9796, 9795, 9794, 9793, 9792, 9791, 9790, 9789, 9788, 9787) 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: 210
# filtered: 100.00
# Extra: Using where; Using index
# Query 3: 294.10 QPS, 0.08x concurrency, ID 0x395AE969FAFDA16C400891B7C96D9565 at byte 4549876
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T14:53:38 to 2023-11-09T14:54:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 17940
# Exec time 16 5s 69us 9ms 260us 657us 252us 176us
# Lock time 15 33ms 0 2ms 1us 1us 14us 1us
# Rows sent 44 592.30k 1 246 33.81 130.47 43.18 19.46
# Rows examine 23 592.30k 1 246 33.81 130.47 43.18 19.46
# Query size 25 3.63M 36 1.36k 211.96 755.64 241.80 130.47
# 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 (211, 438, 80, 798, 379, 833, 497, 808, 827, 187, 639, 57, 993, 379, 355, 955, 756, 263, 720, 844/*... omitted 216 items ...*/)\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: 19
# filtered: 100.00
# Extra: Using where
# Query 4: 319.75 QPS, 0.04x concurrency, ID 0x396201721CD58410E070DA9421CA8C8D at byte 24706521
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T14:53:38 to 2023-11-09T14:54:39
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 16 19505
# Exec time 9 3s 63us 6ms 133us 194us 114us 113us
# Lock time 17 38ms 0 2ms 1us 1us 13us 1us
# Rows sent 1 19.05k 1 1 1 1 0 1
# Rows examine 0 19.05k 1 1 1 1 0 1
# Query size 4 727.26k 37 40 38.18 38.53 0.62 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` = 856\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=1699541618519;before=1699541694773
pprof
go tool pprof -http=0.0.0.0:1080 http://isucon1/pprof/11091153
94539
https://github.com/Saza-ku/private-isu-2023/pull/71