saza-ku / private-isu-2023-public

0 stars 0 forks source link

11091102 #65

Open saza-ku opened 1 year ago

saza-ku commented 1 year ago

isucon1

alp

+-------+--------+---------------+-------+-------+-------+-------+-------+
| COUNT | METHOD |      URI      |  MIN  |  MAX  |  SUM  |  AVG  |  P99  |
+-------+--------+---------------+-------+-------+-------+-------+-------+
| 24    | GET    | /image/.+     | 0.000 | 0.191 | 0.405 | 0.017 | 0.191 |
| 15    | GET    | /             | 0.000 | 0.012 | 0.044 | 0.003 | 0.012 |
| 1     | GET    | /@.+          | 0.020 | 0.020 | 0.020 | 0.020 | 0.020 |
| 2     | POST   | /             | 0.000 | 0.020 | 0.020 | 0.010 | 0.020 |
| 7     | POST   | /login        | 0.004 | 0.004 | 0.008 | 0.001 | 0.004 |
| 1     | POST   | /comment      | 0.008 | 0.008 | 0.008 | 0.008 | 0.008 |
| 2     | GET    | /posts/.+     | 0.004 | 0.004 | 0.008 | 0.004 | 0.004 |
| 1     | POST   | /register     | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |
| 2     | GET    | /login        | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 1     | GET    | /admin/banned | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+---------------+-------+-------+-------+-------+-------+

slow query

Count: 1  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isuconp[isuconp]@localhost
  INSERT INTO `comments` (`post_id`, `user_id`, `comment`) VALUES (N,N,'S')

Count: 3  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=184.3 (553), 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: 1  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=14.0 (14), 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

Count: 1  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=154.0 (154), isuconp[isuconp]@localhost
  SELECT * FROM comments WHERE post_id IN (N, N, N, N, N, N, N, N, N, N, N, N, N, N) ORDER BY `created_at` DESC

Count: 1  Time=0.00s (0s)  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: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isuconp[isuconp]@localhost
  INSERT INTO `users` (`account_name`, `passhash`) VALUES ('S','S')

Count: 3  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=19.7 (59), 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: 2  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=186.0 (372), 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, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N, N)

Count: 7  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.9 (6), isuconp[isuconp]@localhost
  SELECT * FROM users WHERE account_name = 'S' AND del_flg = N

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

explain

Reading from STDIN ...

# 150ms user time, 20ms system time, 36.40M rss, 50.16M vsz
# Current date: Thu Nov  9 23:04:03 2023
# Hostname: private-isu
# Files: STDIN
# Overall: 52 total, 16 unique, 0 QPS, 0x concurrency ____________________
# Time range: all events occurred at 2023-11-09T14:02:46
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           52ms    85us     9ms     1ms     5ms     2ms   185us
# Lock time           84us     1us     3us     1us     1us       0     1us
# Rows sent          1.56k       0     186   30.73  183.58   60.93    0.99
# Rows examine       3.12k       0     372   61.48  299.03  103.54    0.99
# Query size         8.25k      37   1.01k  162.38  793.42  235.20   72.65

# Profile
# Rank Query ID                         Response time Calls R/Call V/M   I
# ==== ================================ ============= ===== ====== ===== =
#    1 0x1ADC9E80BE48F05D4A5F6D6502F...  0.0143 27.4%     6 0.0024  0.00 SELECT comments
#    2 0x9F2038550F51B0A3AB05CA526E3...  0.0086 16.5%     1 0.0086  0.00 INSERT comments
#    3 0x77B9A1E48C001B0D14F8D79F7EA...  0.0057 10.9%     1 0.0057  0.00 SELECT not_banned_posts_without_imgdata
#    4 0x9B36FBB6889AD40E391C181F37D...  0.0048  9.2%     6 0.0008  0.00 SELECT comments
# MISC 0xMISC                            0.0188 36.0%    38 0.0005   0.0 <12 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x1ADC9E80BE48F05D4A5F6D6502F7A387 at byte 844
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2023-11-09T14:02:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11       6
# Exec time     27    14ms   141us     6ms     2ms     6ms     2ms     3ms
# Lock time     10     9us     1us     2us     1us     1us       0     1us
# Rows sent     44     714       0     186     119  183.58   80.79  179.21
# Rows examine  44   1.39k       0     372  236.83  363.48  161.52  354.82
# Query size    10     856      73     188  142.67  183.58   49.64  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 (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: 186
#      filtered: 100.00
#         Extra: Using index condition; Using filesort

# Query 2: 0 QPS, 0x concurrency, ID 0x9F2038550F51B0A3AB05CA526E3FEDDC at byte 6687
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2023-11-09T14:02:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1       1
# Exec time     16     9ms     9ms     9ms     9ms     9ms       0     9ms
# Lock time      1     1us     1us     1us     1us     1us       0     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     1     154     154     154     154     154       0     154
# 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 (7789,309,'こ( ̄0 ̄)ん( ̄ー ̄)に( ̄△ ̄)ち\"<( ̄∇ ̄)>\"わっはっは!!')\G

# Query 3: 0 QPS, 0x concurrency, ID 0x77B9A1E48C001B0D14F8D79F7EAF30FF at byte 3175
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2023-11-09T14:02:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1       1
# Exec time     10     6ms     6ms     6ms     6ms     6ms       0     6ms
# Lock time      2     2us     2us     2us     2us     2us       0     2us
# Rows sent      0      14      14      14      14      14       0      14
# Rows examine   0      14      14      14      14      14       0      14
# Query size     1     149     149     149     149     149       0     149
# String:
# Hosts        localhost
# Users        isuconp
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'not_banned_posts_without_imgdata'\G
#    SHOW CREATE TABLE `not_banned_posts_without_imgdata`\G
# EXPLAIN 
SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `not_banned_posts_without_imgdata` WHERE `user_id` = 81 ORDER BY `created_at` DESC LIMIT 20\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: not_banned_posts_without_imgdata
#    partitions: NULL
#          type: ref
# possible_keys: not_banned_posts_user_id_created_at_index
#           key: not_banned_posts_user_id_created_at_index
#       key_len: 4
#           ref: const
#          rows: 14
#      filtered: 100.00
#         Extra: NULL

# Query 4: 0 QPS, 0x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 2481
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2023-11-09T14:02:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11       6
# Exec time      9     5ms   135us     3ms   799us     3ms   846us   728us
# Lock time      9     8us     1us     2us     1us     1us       0     1us
# Rows sent      4      74       0      20   12.33   19.46    8.39   19.00
# Rows examine  22     714       0     186     119  183.58   80.79  179.21
# Query size    11    1006      98     213  167.67  212.52   48.63  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 (9999, 9998, 9997, 9996, 9995, 9994, 9993, 9991, 9990, 9989, 9988, 9987, 9986, 9985, 9983, 9982, 9981, 9980, 9979, 9977) 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: 186
#      filtered: 100.00
#         Extra: Using where; Using index

netdata

http://localhost:19991/#menu_apps_submenu_cpu;after=1699538566544;before=1699538642898

pprof

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