saza-ku / private-isu-2023-public

0 stars 0 forks source link

11101201 #74

Open saza-ku opened 1 year ago

saza-ku commented 1 year ago

isucon1

alp

+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD |        URI         |  MIN  |  MAX  |  SUM   |  AVG  |  P99  |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 9230  | GET    | /                  | 0.004 | 0.052 | 55.249 | 0.006 | 0.020 |
| 6075  | GET    | /posts/.+          | 0.004 | 0.028 | 24.208 | 0.004 | 0.016 |
| 2355  | GET    | /@.+               | 0.004 | 0.088 | 22.297 | 0.009 | 0.028 |
| 1408  | POST   | /                  | 0.004 | 0.068 | 14.468 | 0.010 | 0.056 |
| 6418  | POST   | /login             | 0.000 | 0.028 | 11.269 | 0.002 | 0.008 |
| 520   | GET    | /posts             | 0.004 | 0.056 | 6.208  | 0.012 | 0.036 |
| 2634  | POST   | /register          | 0.004 | 0.020 | 5.480  | 0.002 | 0.012 |
| 2031  | POST   | /comment           | 0.000 | 0.024 | 4.964  | 0.002 | 0.012 |
| 4181  | GET    | /favicon.ico       | 0.004 | 0.016 | 4.404  | 0.001 | 0.008 |
| 2634  | GET    | /admin/banned      | 0.000 | 0.016 | 4.392  | 0.002 | 0.008 |
| 4181  | GET    | /js/timeago.min.js | 0.004 | 0.024 | 4.284  | 0.001 | 0.008 |
| 4181  | GET    | /js/main.js        | 0.000 | 0.016 | 3.784  | 0.001 | 0.008 |
| 4181  | GET    | /css/style.css     | 0.000 | 0.016 | 3.772  | 0.001 | 0.008 |
| 228   | GET    | /login             | 0.000 | 0.012 | 0.488  | 0.002 | 0.012 |
| 114   | GET    | /logout            | 0.000 | 0.024 | 0.296  | 0.003 | 0.020 |
| 28184 | GET    | /image/.+          | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+

slow query

Count: 9761  Time=0.00s (3s)  Lock=0.00s (0s)  Rows=14.4 (140269), 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: 9761  Time=0.00s (3s)  Lock=0.00s (0s)  Rows=1.8 (17673), 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: 19663  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=1.0 (19663), isuconp[isuconp]@localhost
  SELECT * FROM `users` WHERE `id` = N

Count: 9230  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=20.0 (184600), 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: 6075  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=8.2 (50002), isuconp[isuconp]@localhost
  SELECT * FROM comments WHERE post_id IN (N) ORDER BY `created_at` DESC

Count: 5600  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=19.8 (110799), 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: 6418  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=1.0 (6304), isuconp[isuconp]@localhost
  SELECT * FROM users WHERE account_name = 'S' AND del_flg = N

Count: 6075  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.9 (5292), isuconp[isuconp]@localhost
  SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (N) GROUP BY `post_id`

Count: 6075  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=1.0 (6075), isuconp[isuconp]@localhost
  SELECT * FROM `not_banned_posts_without_imgdata` WHERE `id` = N

Count: 2355  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=10.4 (24481), isuconp[isuconp]@localhost
  SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `not_banned_posts_without_imgdata` WHERE `user_id` = N ORDER BY `created_at` DESC LIMIT N

explain

Reading from STDIN ...

# 9.3s user time, 50ms system time, 37.07M rss, 50.92M vsz
# Current date: Fri Nov 10 00:03:19 2023
# Hostname: private-isu
# Files: STDIN
# Overall: 116.22k total, 22 unique, 1.49k QPS, 0.35x concurrency ________
# Time range: 2023-11-09T15:01:51 to 2023-11-09T15:03:09
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            27s    37us    54ms   232us   541us   419us   159us
# Lock time          205ms       0     1ms     1us     1us     9us     1us
# Rows sent          1.29M       0     246   11.67   54.21   28.16    0.99
# Rows examine       2.49M       0     492   22.42  118.34   51.36    0.99
# Query size        14.18M      17   1.30k  127.91  223.14  116.18   97.36

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0x1ADC9E80BE48F05D4A5F6D65...  7.2667 26.8% 18177 0.0004  0.00 SELECT comments
#    2 0x9B36FBB6889AD40E391C181F...  4.8723 18.0% 18177 0.0003  0.00 SELECT comments
#    3 0x395AE969FAFDA16C400891B7...  4.6135 17.0% 18177 0.0003  0.00 SELECT users
#    4 0x396201721CD58410E070DA94...  2.6224  9.7% 19663 0.0001  0.00 SELECT users
# MISC 0xMISC                         7.6981 28.4% 42026 0.0002   0.0 <18 ITEMS>

# Query 1: 297.98 QPS, 0.12x concurrency, ID 0x1ADC9E80BE48F05D4A5F6D6502F7A387 at byte 66841
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T15:01:51 to 2023-11-09T15:02:52
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         15   18177
# Exec time     26      7s    84us    54ms   399us   972us   928us   260us
# Lock time     16    34ms       0     1ms     1us     1us    14us     1us
# Rows sent     31 416.43k       0     246   23.46  136.99   47.71    0.99
# Rows examine  30 784.02k       0     492   44.17  271.23   96.19    1.96
# Query size    18   2.63M      70     207  151.44  202.40   59.51  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 (7086, 6956, 6441, 6174, 5281, 5029, 5025, 1674, 1147, 489, 441) 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: 118
#      filtered: 100.00
#         Extra: Using index condition; Using filesort

# Query 2: 297.98 QPS, 0.08x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 15640103
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T15:01:51 to 2023-11-09T15:02:52
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         15   18177
# Exec time     17      5s    90us     9ms   268us   445us   225us   247us
# Lock time     14    30ms       0   483us     1us     1us     7us     1us
# Rows sent      3  45.58k       0      20    2.57   13.83    4.58    0.99
# Rows examine  16 416.43k       0     246   23.46  136.99   47.71    0.99
# Query size    21   3.06M      95     232  176.44  223.14   57.69  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 (20592, 20593, 20578, 20579, 20580, 20581, 20582, 20583, 20584, 20585, 20586, 20587, 20588, 20589, 20590, 20591, 20567, 20568, 20569, 20570) 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: 25
#      filtered: 100.00
#         Extra: Using where; Using index

# Query 3: 297.98 QPS, 0.08x concurrency, ID 0x395AE969FAFDA16C400891B7C96D9565 at byte 52888
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T15:01:51 to 2023-11-09T15:02:52
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         15   18177
# Exec time     17      5s    67us    11ms   253us   626us   272us   167us
# Lock time     15    31ms       0   467us     1us     1us     6us     1us
# Rows sent     44 586.09k       1     236   33.02  130.47   42.43   19.46
# Rows examine  23 586.09k       1     236   33.02  130.47   42.43   19.46
# Query size    25   3.60M      36   1.30k  207.54  755.64  238.34  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 (770, 792, 149, 89, 876, 517, 455, 945, 618, 304, 775, 878, 161, 963, 649, 92, 544, 740, 37, 476, 442, 342, 117, 943, 184, 836, 729, 423, 6, 165, 741, 509, 383, 566, 257, 767, 961, 701, 652, 178, 214, 263, 946, 502, 676, 891, 505, 596, 119, 548, 916, 801, 972, 234, 697, 362, 859, 303, 896, 24, 672, 722, 276, 632, 224, 922, 288, 648, 273, 925, 532, 603, 588, 455, 844, 999, 767, 979, 82, 471, 401, 854, 896, 598, 487, 376, 490, 857, 178, 396, 665, 257, 469, 961, 357, 410, 248, 286, 868, 483, 893, 533, 61, 342, 189, 974, 549, 395, 225, 778, 57, 969, 573, 646, 47, 973, 686, 229, 368, 440, 594, 129, 328, 8, 714, 409, 342, 241, 75, 62, 313, 311, 355, 736, 784, 796, 853, 386, 86, 575, 183, 744, 624, 19, 406, 559, 89, 363, 838, 266, 748, 308, 718, 516, 580, 27, 215, 32, 481, 82, 715, 750, 631, 727, 175, 136, 91, 247, 748, 829, 798, 314, 14, 922, 409, 785, 947, 53, 956, 508, 372, 213, 4, 103, 395, 75, 37, 500, 688, 250, 542, 362, 112, 362, 230, 142, 93, 455, 525, 286, 222)\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: 181
#      filtered: 100.00
#         Extra: Using where

# Query 4: 322.34 QPS, 0.04x concurrency, ID 0x396201721CD58410E070DA9421CA8C8D at byte 29290878
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-09T15:01:51 to 2023-11-09T15:02:52
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         16   19663
# Exec time      9      3s    56us     8ms   133us   204us   128us   113us
# Lock time     17    36ms       0     1ms     1us     1us     9us     1us
# Rows sent      1  19.20k       1       1       1       1       0       1
# Rows examine   0  19.20k       1       1       1       1       0       1
# Query size     5 733.25k      37      40   38.19   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` = 702\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=1699542111566;before=1699542187966

pprof

go tool pprof -http=0.0.0.0:1080 http://isucon1/pprof/11101201