11100303

[saza-ku]

isucon1

alp

+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD |        URI         |  MIN  |  MAX  |  SUM   |  AVG  |  P99  |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 6920  | GET    | /                  | 0.004 | 0.100 | 65.552 | 0.009 | 0.028 |
| 6543  | GET    | /posts/.+          | 0.004 | 0.036 | 41.768 | 0.006 | 0.020 |
| 1586  | GET    | /@.+               | 0.004 | 0.072 | 23.580 | 0.015 | 0.036 |
| 1330  | GET    | /posts             | 0.004 | 0.040 | 22.280 | 0.017 | 0.032 |
| 4982  | POST   | /login             | 0.000 | 0.032 | 17.736 | 0.004 | 0.016 |
| 1326  | POST   | /                  | 0.004 | 0.040 | 12.988 | 0.010 | 0.032 |
| 77869 | GET    | /image/.+          | 0.000 | 0.053 | 11.086 | 0.000 | 0.003 |
| 1206  | POST   | /register          | 0.000 | 0.024 | 5.820  | 0.005 | 0.016 |
| 1127  | POST   | /comment           | 0.008 | 0.024 | 4.332  | 0.004 | 0.016 |
| 1206  | GET    | /admin/banned      | 0.000 | 0.020 | 4.296  | 0.004 | 0.012 |
| 882   | GET    | /login             | 0.000 | 0.024 | 2.900  | 0.003 | 0.016 |
| 441   | GET    | /logout            | 0.000 | 0.024 | 1.580  | 0.004 | 0.012 |
| 7267  | GET    | /js/timeago.min.js | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
| 7267  | GET    | /js/main.js        | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
| 7267  | GET    | /css/style.css     | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
| 7267  | GET    | /favicon.ico       | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+

slow query

Count: 8262  Time=0.00s (5s)  Lock=0.00s (0s)  Rows=36.1 (297860), 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: 8262  Time=0.00s (3s)  Lock=0.00s (0s)  Rows=3.9 (32621), 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: 11882  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=1.0 (11882), isuconp[isuconp]@localhost
  SELECT * FROM `users` WHERE `id` = N

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

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

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

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

Count: 3762  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=19.8 (74517), 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: 2331  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=20.7 (48208), 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 ...

# 5.7s user time, 10ms system time, 36.88M rss, 51.32M vsz
# Current date: Fri Nov 10 15:04:29 2023
# Hostname: ip-172-31-22-189
# Files: STDIN
# Overall: 92.94k total, 24 unique, 1.19k QPS, 0.35x concurrency _________
# Time range: 2023-11-10T06:03:06 to 2023-11-10T06:04:24
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            28s    15us    93ms   297us   839us   530us   176us
# Lock time          169ms       0     1ms     1us     4us     7us     1us
# Rows sent          1.36M       0     241   15.39   92.72   37.20    0.99
# Rows examine       2.53M       0     482   28.58  183.58   65.44    3.89
# Query size        12.20M      16   1.28k  137.60  223.14  146.60   97.36

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0x1ADC9E80BE48F05D4A5F6D65...  8.4095 30.5% 16379 0.0005  0.00 SELECT comments
#    2 0x395AE969FAFDA16C400891B7...  5.6387 20.4% 16379 0.0003  0.00 SELECT users
#    3 0x9B36FBB6889AD40E391C181F...  4.8922 17.7% 16379 0.0003  0.00 SELECT comments
#    4 0x396201721CD58410E070DA94...  1.6999  6.2% 11882 0.0001  0.00 SELECT users
# MISC 0xMISC                         6.9682 25.2% 31924 0.0002   0.0 <20 ITEMS>

# Query 1: 268.51 QPS, 0.14x 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-10T06:03:06 to 2023-11-10T06:04:07
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   16379
# Exec time     30      8s    79us    93ms   513us     1ms     1ms   287us
# Lock time     17    30ms       0   765us     1us     3us     8us     1us
# Rows sent     35 498.50k       0     241   31.17  192.76   59.32    5.75
# Rows examine  36 942.19k       0     482   58.90  381.65  119.84    5.75
# Query size    18   2.25M      70     207  144.12  202.40   60.52  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 (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: 220
#      filtered: 100.00
#         Extra: Using index condition; Using filesort

# Query 2: 268.51 QPS, 0.09x concurrency, ID 0x395AE969FAFDA16C400891B7C96D9565 at byte 22366495
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T06:03:06 to 2023-11-10T06:04:07
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   16379
# Exec time     20      6s    56us     9ms   344us     1ms   399us   185us
# Lock time     16    29ms       0   269us     1us     4us     4us     1us
# Rows sent     44 625.81k       1     232   39.13  192.76   54.54   19.46
# Rows examine  24 625.81k       1     232   39.13  192.76   54.54   19.46
# Query size    30   3.76M      36   1.28k  240.80   1.04k  302.00  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 (293, 13, 672, 211, 438, 80, 798, 379, 833, 497, 808, 827, 187, 639, 57, 993, 379, 355, 955, 756/*... omitted 234 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 3: 268.51 QPS, 0.08x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 55813
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T06:03:06 to 2023-11-10T06:04:07
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   16379
# Exec time     17      5s    79us     5ms   298us   626us   220us   260us
# Lock time     15    27ms       0   582us     1us     1us     5us     1us
# Rows sent      3  52.81k       0      20    3.30   19.46    5.73    0.99
# Rows examine  19 498.50k       0     241   31.17  192.76   59.32    5.75
# Query size    21   2.64M      95     232  169.12  223.14   58.60  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 (12804, 10000, 9999, 9998, 9997, 9996, 9995, 9994, 9993, 9991, 9990, 9989, 9988, 9987, 9986, 9985, 9983, 9982, 9981, 9980) 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: 216
#      filtered: 100.00
#         Extra: Using where; Using index

# Query 4: 194.79 QPS, 0.03x concurrency, ID 0x396201721CD58410E070DA9421CA8C8D at byte 41220
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-10T06:03:06 to 2023-11-10T06:04:07
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         12   11882
# Exec time      6      2s    54us     5ms   143us   316us   132us   103us
# Lock time     13    23ms       0   670us     1us     4us     9us     1us
# Rows sent      0  11.60k       1       1       1       1       0       1
# Rows examine   0  11.60k       1       1       1       1       0       1
# Query size     3 441.19k      37      39   38.02   38.53    0.55   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` = 635\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=1699596186723;before=1699596262975

pprof

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