11100201

[saza-ku]

isucon1

alp

+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD |        URI         |  MIN  |  MAX  |  SUM   |  AVG  |  P99  |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 4858  | GET    | /                  | 0.000 | 0.076 | 78.168 | 0.016 | 0.044 |
| 704   | GET    | /@.+               | 0.032 | 0.288 | 60.772 | 0.086 | 0.160 |
| 3390  | GET    | /posts/.+          | 0.004 | 0.048 | 37.348 | 0.011 | 0.036 |
| 1260  | GET    | /posts             | 0.004 | 0.072 | 31.448 | 0.025 | 0.052 |
| 3367  | POST   | /login             | 0.000 | 0.044 | 18.616 | 0.006 | 0.024 |
| 958   | POST   | /                  | 0.004 | 0.064 | 15.024 | 0.016 | 0.056 |
| 4438  | GET    | /favicon.ico       | 0.000 | 0.028 | 11.908 | 0.003 | 0.016 |
| 4438  | GET    | /js/timeago.min.js | 0.000 | 0.032 | 10.876 | 0.002 | 0.012 |
| 4438  | GET    | /js/main.js        | 0.000 | 0.036 | 10.636 | 0.002 | 0.012 |
| 4438  | GET    | /css/style.css     | 0.000 | 0.024 | 10.276 | 0.002 | 0.016 |
| 65479 | GET    | /image/.+          | 0.000 | 0.028 | 7.583  | 0.000 | 0.003 |
| 847   | POST   | /register          | 0.004 | 0.036 | 6.380  | 0.008 | 0.032 |
| 847   | GET    | /admin/banned      | 0.004 | 0.040 | 5.000  | 0.006 | 0.020 |
| 734   | GET    | /login             | 0.000 | 0.032 | 3.572  | 0.005 | 0.020 |
| 461   | POST   | /comment           | 0.004 | 0.036 | 2.812  | 0.006 | 0.024 |
| 367   | GET    | /logout            | 0.000 | 0.032 | 1.800  | 0.005 | 0.020 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+

slow query

Count: 704  Time=0.06s (42s)  Lock=0.00s (0s)  Rows=1.0 (704), isuconp[isuconp]@localhost
  SELECT COUNT(*) AS count FROM `comments` WHERE `user_id` = N

Count: 6120  Time=0.00s (6s)  Lock=0.00s (0s)  Rows=44.5 (272426), 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: 6120  Time=0.00s (5s)  Lock=0.00s (0s)  Rows=4.6 (28083), 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: 7147  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=1.0 (7147), isuconp[isuconp]@localhost
  SELECT * FROM `users` WHERE `id` = N

Count: 4858  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=20.0 (97160), 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: 3929  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=19.9 (78262), 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: 3367  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=0.9 (3000), isuconp[isuconp]@localhost
  SELECT * FROM users WHERE account_name = 'S' AND del_flg = N

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

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

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

explain

Reading from STDIN ...

# 3.7s user time, 40ms system time, 36.88M rss, 51.31M vsz
# Current date: Fri Nov 10 14:02:33 2023
# Hostname: ip-172-31-22-189
# Files: STDIN
# Overall: 56.83k total, 24 unique, 747.75 QPS, 1.00x concurrency ________
# Time range: 2023-11-10T05:01:13 to 2023-11-10T05:02:29
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            76s    27us   244ms     1ms     3ms     7ms   273us
# Lock time          188ms       0     6ms     3us     3us    50us     1us
# Rows sent        997.66k       0     230   17.98  130.47   42.25    0.99
# Rows examine      68.98M       0  98.11k   1.24k  202.40  10.73k    1.96
# Query size         8.09M      16   1.22k  149.25  223.14  164.55  124.25

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0xCDEB1AFF2AE2BE51B2ED5CF0... 42.7848 56.5%   704 0.0608  0.01 SELECT comments
#    2 0x1ADC9E80BE48F05D4A5F6D65...  8.9932 11.9% 10212 0.0009  0.00 SELECT comments
#    3 0x9B36FBB6889AD40E391C181F...  6.6595  8.8% 10212 0.0007  0.00 SELECT comments
#    4 0x395AE969FAFDA16C400891B7...  6.3454  8.4% 10212 0.0006  0.00 SELECT users
# MISC 0xMISC                        10.9112 14.4% 25489 0.0004   0.0 <20 ITEMS>

# Query 1: 11.73 QPS, 0.71x concurrency, ID 0xCDEB1AFF2AE2BE51B2ED5CF03D4E749F at byte 4971
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2023-11-10T05:01:13 to 2023-11-10T05:02:13
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1     704
# Exec time     56     43s    21ms   244ms    61ms   100ms    22ms    53ms
# Lock time      0     1ms       0    74us     1us     1us     3us     1us
# Rows sent      0     704       1       1       1       1       0       1
# Rows examine  97  67.29M  97.66k  98.11k  97.88k  97.04k       0  97.04k
# Query size     0  42.57k      61      62   61.92   59.77       0   59.77
# 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 COUNT(*) AS count FROM `comments` WHERE `user_id` = 416\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: comments
#    partitions: NULL
#          type: ALL
# possible_keys: NULL
#           key: NULL
#       key_len: NULL
#           ref: NULL
#          rows: 100662
#      filtered: 10.00
#         Extra: Using where

# Query 2: 167.41 QPS, 0.15x concurrency, ID 0x1ADC9E80BE48F05D4A5F6D6502F7A387 at byte 3559
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:01:13 to 2023-11-10T05:02:14
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   10212
# Exec time     11      9s    96us    31ms   880us     3ms     1ms   366us
# Lock time     18    35ms       0     3ms     3us     2us    47us     1us
# Rows sent     36 361.13k       0     230   36.21  192.76   66.48    0.99
# Rows examine   0 695.08k       0     460   69.70  400.73  134.03    1.96
# Query size    18   1.50M      70     207  154.40  202.40   59.08  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 
SELECT * FROM comments WHERE post_id IN (9590, 9475, 8283, 6088, 4897, 3696, 2062, 1759, 744, 459) 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: 90
#      filtered: 100.00
#         Extra: Using index condition; Using filesort

# Query 3: 167.41 QPS, 0.11x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 16956213
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:01:13 to 2023-11-10T05:02:14
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   10212
# Exec time      8      7s    86us    16ms   652us     3ms     1ms   332us
# Lock time     14    27ms       0     2ms     2us     2us    28us     1us
# Rows sent      3  37.04k       0      20    3.71   19.46    6.62    0.99
# Rows examine   0 361.13k       0     230   36.21  192.76   66.48    0.99
# Query size    21   1.75M      95     232  179.40  223.14   57.19  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 (10404, 10405, 10396, 10397, 10398, 10399, 10400, 10401, 10402, 10403, 10389, 10390, 10391, 10392, 10393, 10394, 10395, 10382, 10383, 10384) 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: 20
#      filtered: 100.00
#         Extra: Using where; Using index

# Query 4: 167.41 QPS, 0.10x concurrency, ID 0x395AE969FAFDA16C400891B7C96D9565 at byte 5866468
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T05:01:13 to 2023-11-10T05:02:14
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   10212
# Exec time      8      6s    64us    24ms   621us     2ms     1ms   236us
# Lock time     16    32ms       0     4ms     3us     2us    55us     1us
# Rows sent     45 450.71k       1     227   45.19  192.76   61.09   19.46
# Rows examine   0 450.71k       1     227   45.19  192.76   61.09   19.46
# Query size    32   2.65M      36   1.22k  272.62   1.04k  336.94  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 (925, 384, 475, 522, 273, 270, 662, 620, 114, 93, 195, 76, 529, 938, 487, 814, 280, 655, 717, 649)\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: 20
#      filtered: 100.00
#         Extra: Using where

netdata

http://localhost:19991/#menu_apps_submenu_cpu;after=1699592472561;before=1699592548602

pprof

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