11160452

[saza-ku]

isucon1

alp

+-------+--------+--------------------+-------+-------+--------+-------+-------+
| COUNT | METHOD |        URI         |  MIN  |  MAX  |  SUM   |  AVG  |  P99  |
+-------+--------+--------------------+-------+-------+--------+-------+-------+
| 6391  | GET    | /                  | 0.004 | 0.052 | 65.575 | 0.010 | 0.028 |
| 6302  | GET    | /posts/.+          | 0.008 | 0.040 | 44.931 | 0.007 | 0.024 |
| 1490  | GET    | /@.+               | 0.004 | 0.056 | 24.560 | 0.016 | 0.040 |
| 1300  | GET    | /posts             | 0.004 | 0.052 | 23.292 | 0.018 | 0.036 |
| 4582  | POST   | /login             | 0.000 | 0.024 | 18.796 | 0.004 | 0.016 |
| 1198  | POST   | /                  | 0.000 | 0.056 | 13.572 | 0.011 | 0.040 |
| 74893 | GET    | /image/.+          | 0.000 | 0.041 | 11.801 | 0.000 | 0.004 |
| 1110  | POST   | /register          | 0.000 | 0.020 | 5.828  | 0.005 | 0.016 |
| 1026  | POST   | /comment           | 0.004 | 0.028 | 4.616  | 0.004 | 0.016 |
| 1110  | GET    | /admin/banned      | 0.000 | 0.020 | 4.468  | 0.004 | 0.016 |
| 832   | GET    | /login             | 0.004 | 0.024 | 3.104  | 0.004 | 0.016 |
| 416   | GET    | /logout            | 0.000 | 0.028 | 1.732  | 0.004 | 0.016 |
| 7088  | GET    | /js/timeago.min.js | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
| 7088  | GET    | /js/main.js        | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
| 7088  | GET    | /css/style.css     | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
| 7088  | GET    | /favicon.ico       | 0.000 | 0.000 | 0.000  | 0.000 | 0.000 |
+-------+--------+--------------------+-------+-------+--------+-------+-------+

slow query

Count: 7698  Time=0.00s (5s)  Lock=0.00s (0s)  Rows=39.0 (299856), 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: 7698  Time=0.00s (3s)  Lock=0.00s (0s)  Rows=4.1 (31798), 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: 10845  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=1.0 (10845), isuconp[isuconp]@localhost
  SELECT * FROM `users` WHERE `id` = N

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

Count: 6391  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=20.0 (127820), 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: 6302  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=0.9 (5600), isuconp[isuconp]@localhost
  SELECT `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (N) GROUP BY `post_id`

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

Count: 4105  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=19.7 (80817), 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: 4582  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.9 (4166), isuconp[isuconp]@localhost
  SELECT * FROM users WHERE account_name = 'S' AND del_flg = N

Count: 1300  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=20.0 (26000), isuconp[isuconp]@localhost
  SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `not_banned_posts_without_imgdata` WHERE `created_at` <= 'S' ORDER BY `created_at` DESC LIMIT N

explain

Reading from STDIN ...

# 5.4s user time, 40ms system time, 36.88M rss, 51.33M vsz
# Current date: Thu Nov 16 16:54:15 2023
# Hostname: ip-172-31-22-189
# Files: STDIN
# Overall: 87.18k total, 24 unique, 1.13k QPS, 0.36x concurrency _________
# Time range: 2023-11-16T07:52:52 to 2023-11-16T07:54:09
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            28s    27us    41ms   317us   925us   472us   194us
# Lock time          172ms       0     2ms     1us     4us     8us     1us
# Rows sent          1.32M       0     241   15.84   97.36   37.75    0.99
# Rows examine       2.45M       0     482   29.48  183.58   66.23    5.75
# Query size        11.52M      16   1.28k  138.53  223.14  148.41   97.36

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0x1ADC9E80BE48F05D4A5F6D65...  8.3605 30.2% 15483 0.0005  0.00 SELECT comments
#    2 0x395AE969FAFDA16C400891B7...  5.6144 20.3% 15483 0.0004  0.00 SELECT users
#    3 0x9B36FBB6889AD40E391C181F...  4.8394 17.5% 15483 0.0003  0.00 SELECT comments
#    4 0x396201721CD58410E070DA94...  1.6545  6.0% 10845 0.0002  0.00 SELECT users
# MISC 0xMISC                         7.1981 26.0% 29887 0.0002   0.0 <20 ITEMS>

# Query 1: 253.82 QPS, 0.14x concurrency, ID 0x1ADC9E80BE48F05D4A5F6D6502F7A387 at byte 847
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-16T07:52:52 to 2023-11-16T07:53:53
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   15483
# Exec time     30      8s    85us    41ms   539us     2ms   900us   301us
# Lock time     17    30ms       0     2ms     1us     4us    14us     1us
# Rows sent     36 488.53k       0     241   32.31  192.76   59.71    6.98
# Rows examine  36 923.85k       0     482   61.10  381.65  120.64    6.98
# Query size    18   2.11M      70     207  142.93  202.40   60.49  158.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: 207
#      filtered: 100.00
#         Extra: Using index condition; Using filesort

# Query 2: 253.82 QPS, 0.09x concurrency, ID 0x395AE969FAFDA16C400891B7C96D9565 at byte 3823561
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-16T07:52:52 to 2023-11-16T07:53:53
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   15483
# Exec time     20      6s    63us     8ms   362us     1ms   415us   194us
# Lock time     16    28ms       0   204us     1us     1us     4us     1us
# Rows sent     44 604.51k       1     234   39.98  192.76   55.06   19.46
# Rows examine  24 604.51k       1     234   39.98  192.76   55.06   19.46
# Query size    31   3.63M      36   1.28k  245.65   1.04k  304.40  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 (130, 869, 306, 6, 316, 593, 691, 234, 492, 894, 369, 743, 863, 60, 603, 360, 130, 478, 607, 340, 95, 302, 691, 871, 593, 913, 65, 788, 259, 394, 756, 824, 508, 507, 766, 583, 126, 580, 674, 995, 876, 645, 454, 687, 556, 424, 91, 185, 353, 520, 477, 87, 608, 718, 80, 592, 649, 43, 618, 695, 249, 435, 8, 878, 990, 676, 869, 729, 743, 304, 125, 666, 901, 952, 779, 954, 638, 925, 798, 412, 357, 479, 763, 878, 931, 10, 979, 389, 83, 850, 127, 408, 606, 308, 661, 87, 555, 284, 444, 531, 290, 284, 470, 296, 611, 797, 254, 188, 1000, 113, 778, 713, 511, 987, 861, 999, 957, 310, 87, 733, 189, 876, 147, 192, 627, 473, 335, 342, 777, 163, 395, 526, 645, 488, 798, 73, 279, 574, 694, 980, 525, 534, 493, 623, 691, 181, 359, 327, 333, 255, 222, 982, 555, 201, 808, 440, 410, 817, 719, 160, 606, 281, 641, 953, 24, 768, 162, 791, 455, 110, 615, 578, 334, 638, 338, 594, 355, 166, 420, 841, 38, 706, 196, 472, 431, 15, 984, 167, 867, 731, 113, 698, 661, 68, 559, 971, 718, 667)\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: 179
#      filtered: 100.00
#         Extra: Using where

# Query 3: 253.82 QPS, 0.08x concurrency, ID 0x9B36FBB6889AD40E391C181F37DD0542 at byte 19882632
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-16T07:52:52 to 2023-11-16T07:53:53
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   15483
# Exec time     17      5s    80us     8ms   312us   657us   255us   273us
# Lock time     15    27ms       0   390us     1us     1us     5us     1us
# Rows sent      3  50.83k       0      20    3.36   19.46    5.82    0.99
# Rows examine  19 488.54k       0     241   32.31  192.76   59.71    6.98
# Query size    21   2.48M      95     232  167.93  223.14   58.57  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 `post_id`, COUNT(*) AS `count` FROM `comments` WHERE `post_id` IN (13854, 13855, 13856, 13857, 13858, 13859, 13860, 13861, 13862, 13843, 13844, 13845, 13846, 13847, 13848, 13849, 13850, 13851, 13852, 13853) 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: 177.79 QPS, 0.03x concurrency, ID 0x396201721CD58410E070DA9421CA8C8D at byte 18699909
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-16T07:52:52 to 2023-11-16T07:53:53
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         12   10845
# Exec time      5      2s    56us     5ms   152us   348us   145us   108us
# Lock time     12    22ms       0   827us     2us     5us     8us     1us
# Rows sent      0  10.59k       1       1       1       1       0       1
# Rows examine   0  10.59k       1       1       1       1       0       1
# Query size     3 402.78k      37      39   38.03   38.53    0.56   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` = 923\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=1700121172128;before=1700121248451

pprof

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