hoge-times / isucon9-qualify-20240217

MIT License
0 stars 0 forks source link

add created_at_idx #6

Closed meihei3 closed 7 months ago

meihei3 commented 7 months ago
{"pass":true,"score":2210,"campaign":0,"language":"Go","messages":[]}
isucon@ip-172-31-0-240:~/isucari$ sudo cat /var/log/nginx/access.log | alp ltsv -m "/items/\d+.json","/users/\d+.json","/upload/[\w\d]+.jpg","/transactions/\d+.png","/new_items/\d+.json" --sort=sum --reverse --filters 'Time > TimeAgo("10m")'
+-------+-----+------+-----+-----+-----+--------+-------------------------------------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
| COUNT | 1XX | 2XX  | 3XX | 4XX | 5XX | METHOD |                 URI                 |  MIN  |  MAX  |   SUM   |  AVG  |  P90  |  P95  |  P99  | STDDEV | MIN(BODY)  | MAX(BODY)  |  SUM(BODY)   | AVG(BODY)  |
+-------+-----+------+-----+-----+-----+--------+-------------------------------------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
| 171   | 0   | 160  | 0   | 11  | 0   | GET    | /users/transactions.json            | 0.024 | 7.116 | 472.939 | 2.766 | 4.872 | 5.234 | 6.860 | 1.724  | 0.000      | 29151.000  | 3293446.000  | 19259.918  |
| 915   | 0   | 915  | 0   | 0   | 0   | GET    | /new_items/\d+.json                 | 0.028 | 0.924 | 121.088 | 0.132 | 0.304 | 0.340 | 0.416 | 0.106  | 22653.000  | 24058.000  | 21494736.000 | 23491.515  |
| 273   | 0   | 273  | 0   | 0   | 0   | GET    | /users/\d+.json                     | 0.020 | 1.452 | 105.352 | 0.386 | 0.876 | 1.004 | 1.300 | 0.321  | 97.000     | 23943.000  | 3847432.000  | 14093.158  |
| 55    | 0   | 31   | 0   | 24  | 0   | POST   | /buy                                | 0.440 | 1.644 | 53.688  | 0.976 | 1.616 | 1.620 | 1.644 | 0.780  | 0.000      | 49.000     | 1963.000     | 35.691     |
| 132   | 0   | 132  | 0   | 0   | 0   | GET    | /new_items.json                     | 0.024 | 0.540 | 22.852  | 0.173 | 0.332 | 0.360 | 0.484 | 0.126  | 23025.000  | 23959.000  | 3091696.000  | 23421.939  |
| 39    | 0   | 29   | 0   | 10  | 0   | POST   | /ship                               | 0.808 | 0.824 | 21.168  | 0.543 | 0.816 | 0.820 | 0.824 | 0.382  | 29.000     | 61.000     | 2099.000     | 53.821     |
| 40    | 0   | 24   | 0   | 16  | 0   | POST   | /ship_done                          | 0.570 | 0.820 | 20.802  | 0.520 | 0.812 | 0.812 | 0.820 | 0.382  | 0.000      | 83.000     | 1561.000     | 39.025     |
| 3     | 0   | 1    | 0   | 0   | 2   | POST   | /initialize                         | 5.860 | 6.416 | 18.496  | 6.165 | 6.416 | 6.416 | 6.416 | 0.230  | 21.000     | 31.000     | 73.000       | 24.333     |
| 23    | 0   | 22   | 0   | 1   | 0   | POST   | /complete                           | 0.008 | 0.816 | 16.153  | 0.702 | 0.808 | 0.808 | 0.816 | 0.267  | 0.000      | 34.000     | 748.000      | 32.522     |
| 2681  | 0   | 2681 | 0   | 0   | 0   | GET    | /items/\d+.json                     | 0.004 | 0.284 | 12.840  | 0.005 | 0.012 | 0.012 | 0.024 | 0.009  | 1851.000   | 4056.000   | 5869390.000  | 2189.254   |
| 61    | 0   | 53   | 0   | 8   | 0   | POST   | /login                              | 0.060 | 0.480 | 11.644  | 0.191 | 0.336 | 0.356 | 0.480 | 0.102  | 73.000     | 104.000    | 5753.000     | 94.311     |
| 53    | 0   | 53   | 0   | 0   | 0   | GET    | /settings                           | 0.004 | 0.200 | 2.824   | 0.053 | 0.148 | 0.160 | 0.200 | 0.058  | 2936.000   | 2950.000   | 156007.000   | 2943.528   |
| 54    | 0   | 36   | 0   | 18  | 0   | POST   | /sell                               | 0.004 | 0.316 | 1.624   | 0.030 | 0.108 | 0.156 | 0.316 | 0.061  | 13.000     | 106.000    | 1914.000     | 35.444     |
| 13    | 0   | 13   | 0   | 0   | 0   | POST   | /bump                               | 0.004 | 0.220 | 0.340   | 0.026 | 0.032 | 0.220 | 0.220 | 0.056  | 90.000     | 91.000     | 1180.000     | 90.769     |
| 35    | 0   | 25   | 0   | 10  | 0   | GET    | /transactions/\d+.png               | 0.000 | 0.008 | 0.084   | 0.002 | 0.004 | 0.008 | 0.008 | 0.002  | 33.000     | 622.000    | 15661.000    | 447.457    |
| 8     | 0   | 3    | 0   | 5   | 0   | POST   | /items/edit                         | 0.004 | 0.028 | 0.052   | 0.007 | 0.028 | 0.028 | 0.028 | 0.008  | 58.000     | 93.000     | 567.000      | 70.875     |
| 57    | 0   | 57   | 0   | 0   | 0   | GET    | /upload/[\w\d]+.jpg                 | 0.000 | 0.004 | 0.032   | 0.001 | 0.004 | 0.004 | 0.004 | 0.001  | 52927.000  | 153237.000 | 4474763.000  | 78504.614  |
| 1     | 0   | 1    | 0   | 0   | 0   | GET    | /reports.json                       | 0.004 | 0.004 | 0.004   | 0.004 | 0.004 | 0.004 | 0.004 | 0.000  | 108991.000 | 108991.000 | 108991.000   | 108991.000 |
| 1     | 0   | 1    | 0   | 0   | 0   | GET    | /static/css/main.19393e92.chunk.css | 0.000 | 0.000 | 0.000   | 0.000 | 0.000 | 0.000 | 0.000 | 0.000  | 994.000    | 994.000    | 994.000      | 994.000    |
| 1     | 0   | 1    | 0   | 0   | 0   | GET    | /static/js/main.babc3d4d.chunk.js   | 0.000 | 0.000 | 0.000   | 0.000 | 0.000 | 0.000 | 0.000 | 0.000  | 90365.000  | 90365.000  | 90365.000    | 90365.000  |
| 1     | 0   | 1    | 0   | 0   | 0   | GET    | /static/js/runtime~main.a8a9905a.js | 0.000 | 0.000 | 0.000   | 0.000 | 0.000 | 0.000 | 0.000 | 0.000  | 1502.000   | 1502.000   | 1502.000     | 1502.000   |
| 1     | 0   | 1    | 0   | 0   | 0   | GET    | /static/js/2.ff6e1067.chunk.js      | 0.000 | 0.000 | 0.000   | 0.000 | 0.000 | 0.000 | 0.000 | 0.000  | 508459.000 | 508459.000 | 508459.000   | 508459.000 |
+-------+-----+------+-----+-----+-----+--------+-------------------------------------+-------+-------+---------+-------+-------+-------+-------+--------+------------+------------+--------------+------------+
meihei3 commented 7 months ago

# 36.8s user time, 290ms system time, 48.08M rss, 112.34M vsz
# Current date: Sat Feb 17 07:38:46 2024
# Hostname: ip-172-31-0-240
# Files: /var/log/mysql/slow.log
# Overall: 595.22k total, 66 unique, 3.54k QPS, 1.33x concurrency ________
# Time range: 2024-02-17T07:29:14 to 2024-02-17T07:32:02
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           223s     1us      1s   374us   568us    10ms    52us
# Lock time             9s       0    15ms    15us    19us   198us       0
# Rows sent        255.70k       0      49    0.44    0.99    2.18       0
# Rows examine      10.54M       0  48.86k   18.56    0.99  782.25       0
# Query size       379.90M       0 913.29k  669.26   40.45  20.45k   31.70

# Profile
# Rank Query ID           Response time Calls  R/Call V/M   Item
# ==== ================== ============= ====== ====== ===== ==============
#    1 0x312243B842F41381 65.2713 29.2%    167 0.3908  0.27 SELECT items
#    2 0x99AA0165670CE848 34.7006 15.5% 197542 0.0002  0.00 ADMIN PREPARE
#    3 0xD12C53668328DB0D 29.6490 13.3% 128193 0.0002  0.00 SELECT categories
#    4 0x36DB5799406088D9 24.9370 11.2%    106 0.2353  0.20 SELECT items
#    5 0x2C1B6BE83F13FC2B 21.8885  9.8%    110 0.1990  0.29 SELECT items
#    6 0xE070DA9421CA8C8D 15.5405  7.0%  59814 0.0003  0.00 SELECT users
#    7 0x54AA9C3947003532  9.4571  4.2%    300 0.0315  0.01 INSERT items
#    8 0x930FF1E60F9B9ED6  6.8657  3.1%    805 0.0085  0.01 SELECT items
#    9 0x4C4F0D7D775BE587  3.5974  1.6%    294 0.0122  0.01 INSERT transaction_evidences
#   10 0x4C0C6A2C3174E3A8  2.8279  1.3%     61 0.0464  0.02 SELECT items
# MISC 0xMISC              8.4214  3.8% 207827 0.0000   0.0 <56 ITEMS>

# Query 1: 2.69 QPS, 1.05x concurrency, ID 0x312243B842F41381 at byte 408115109
# Scores: V/M = 0.27
# Time range: 2024-02-17T07:30:58 to 2024-02-17T07:32:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     167
# Exec time     29     65s    32ms      1s   391ms      1s   323ms   241ms
# Lock time      0    10ms    19us     2ms    61us   194us   144us    27us
# Rows sent      1   4.36k       0      49   26.72   46.83   22.75   46.83
# Rows examine  52   5.52M  19.33k  48.86k  33.82k  46.68k  13.26k  20.37k
# Query size     0  23.11k     140     142  141.69  136.99       0  136.99
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms  ############
# 100ms  ################################################################
#    1s  #####
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'items'\G
#    SHOW CREATE TABLE `isucari`.`items`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `items` WHERE `seller_id` = 422 AND `status` IN ('on_sale','trading','sold_out') ORDER BY `created_at` DESC, `id` DESC LIMIT 49\G

# Query 2: 3.09k QPS, 0.54x concurrency, ID 0x99AA0165670CE848 at byte 382421136
# Scores: V/M = 0.00
# Time range: 2024-02-17T07:30:58 to 2024-02-17T07:32:02
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         33  197542
# Exec time     15     35s    21us   151ms   175us   596us   587us    69us
# Lock time      0       0       0       0       0       0       0       0
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     1   5.65M      30      30      30      30       0      30
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us  ################################################################
# 100us  ###############################
#   1ms  ##
#  10ms  #
# 100ms  #
#    1s
#  10s+
administrator command: Prepare\G

# Query 3: 2.00k QPS, 0.46x concurrency, ID 0xD12C53668328DB0D at byte 393131839
# Scores: V/M = 0.00
# Time range: 2024-02-17T07:30:58 to 2024-02-17T07:32:02
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         21  128193
# Exec time     13     30s    33us    22ms   231us   799us   464us   108us
# Lock time     40      4s     8us    15ms    29us    69us   146us    14us
# Rows sent     48 125.19k       1       1       1       1       0       1
# Rows examine   1 125.19k       1       1       1       1       0       1
# Query size     1   5.12M      41      42   41.87   40.45       0   40.45
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us  #######################################################
# 100us  ################################################################
#   1ms  ####
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'categories'\G
#    SHOW CREATE TABLE `isucari`.`categories`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `categories` WHERE `id` = 40\G

# Query 4: 1.77 QPS, 0.42x concurrency, ID 0x36DB5799406088D9 at byte 414201219
# Scores: V/M = 0.20
# Time range: 2024-02-17T07:30:59 to 2024-02-17T07:31:59
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     106
# Exec time     11     25s    13ms   792ms   235ms   705ms   215ms   155ms
# Lock time      0     9ms    28us   866us    82us   204us   126us    36us
# Rows sent      1   3.43k      15      49   33.16   46.83   15.01   46.83
# Rows examine  14   1.49M   6.88k  21.44k  14.40k  21.38k   6.74k  19.40k
# Query size     0  25.38k     243     246  245.19  234.30       0  234.30
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms  ##############################
# 100ms  ################################################################
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'items'\G
#    SHOW CREATE TABLE `isucari`.`items`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `items` WHERE `seller_id` = 733 AND `status` IN ('on_sale','trading','sold_out') AND (`created_at` < '2019-08-12 10:06:22'  OR (`created_at` <= '2019-08-12 10:06:22' AND `id` < 29179)) ORDER BY `created_at` DESC, `id` DESC LIMIT 49\G

# Query 5: 1.77 QPS, 0.35x concurrency, ID 0x2C1B6BE83F13FC2B at byte 402923245
# Scores: V/M = 0.29
# Time range: 2024-02-17T07:30:59 to 2024-02-17T07:32:01
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     110
# Exec time      9     22s     5ms      1s   199ms   609ms   241ms    78ms
# Lock time      0     5ms    21us   462us    49us   176us    62us    28us
# Rows sent      0     959       4      11    8.72   10.84    2.62   10.84
# Rows examine  25   2.70M   2.59k  48.86k  25.14k  46.68k  21.41k   4.27k
# Query size     0  19.38k     177     181  180.40  174.84    0.00  174.84
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  #####################
#  10ms  ################################################################
# 100ms  ##########################################################
#    1s  ##
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'items'\G
#    SHOW CREATE TABLE `isucari`.`items`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `items` WHERE (`seller_id` = 2363 OR `buyer_id` = 2363) AND `status` IN ('on_sale','trading','sold_out','cancel','stop') ORDER BY `created_at` DESC, `id` DESC LIMIT 11\G

# Query 6: 934.59 QPS, 0.24x concurrency, ID 0xE070DA9421CA8C8D at byte 504724937
# Scores: V/M = 0.00
# Time range: 2024-02-17T07:30:58 to 2024-02-17T07:32:02
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         10   59814
# Exec time      6     16s    41us    25ms   259us   881us   542us   119us
# Lock time     20      2s     8us    12ms    32us    80us   139us    15us
# Rows sent     22  58.41k       1       1       1       1       0       1
# Rows examine   0  58.41k       1       1       1       1       0       1
# Query size     0   2.21M      36      39   38.73   38.53    0.79   38.53
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us  ######################################################
# 100us  ################################################################
#   1ms  #####
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'users'\G
#    SHOW CREATE TABLE `isucari`.`users`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `users` WHERE `id` = 1760\G

# Query 7: 6.25 QPS, 0.20x concurrency, ID 0x54AA9C3947003532 at byte 235704880
# Scores: V/M = 0.01
# Time range: 2024-02-17T07:30:10 to 2024-02-17T07:30:58
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     300
# Exec time      4      9s    18ms   170ms    32ms    51ms    17ms    27ms
# Lock time     25      2s     6ms    11ms     8ms     9ms   463us     8ms
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    70 265.95M 728.39k 913.29k 907.78k 871.90k  15.38k 871.90k
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms  ################################################################
# 100ms  #
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'items'\G
#    SHOW CREATE TABLE `isucari`.`items`\G

# Query 8: 13.64 QPS, 0.12x concurrency, ID 0x930FF1E60F9B9ED6 at byte 386262126
# Scores: V/M = 0.01
# Time range: 2024-02-17T07:30:59 to 2024-02-17T07:31:58
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     805
# Exec time      3      7s   920us    65ms     9ms    30ms     9ms     5ms
# Lock time      0    63ms    25us     3ms    77us   214us   148us    38us
# Rows sent     15  38.52k      49      49      49      49       0      49
# Rows examine   2 296.58k     173     816  377.27  652.75  132.93  329.68
# Query size     0 198.88k     248     257  252.98  246.02       0  246.02
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us
# 100us  #
#   1ms  ################################################################
#  10ms  #######################
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'items'\G
#    SHOW CREATE TABLE `isucari`.`items`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM `items` WHERE `status` IN ('on_sale','sold_out') AND category_id IN (31, 32, 33, 34, 35) AND (`created_at` < '2019-08-12 15:29:21'  OR (`created_at` <= '2019-08-12 15:29:21' AND `id` < 48558)) ORDER BY `created_at` DESC, `id` DESC LIMIT 49\G

# Query 9: 6.12 QPS, 0.07x concurrency, ID 0x4C4F0D7D775BE587 at byte 128028186
# Scores: V/M = 0.01
# Time range: 2024-02-17T07:30:10 to 2024-02-17T07:30:58
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     294
# Exec time      1      4s     4ms    81ms    12ms    23ms    10ms     8ms
# Lock time      6   581ms   780us     3ms     2ms     2ms   208us     2ms
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    20  78.46M 109.39k 308.18k 273.27k 298.06k  23.12k 270.35k
# String:
# Databases    isucari
# Hosts        localhost
# Users        isucari
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms  ###################################
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isucari` LIKE 'transaction_evidences'\G
#    SHOW CREATE TABLE `isucari`.`transaction_evidences`\G

# Query 10: 1 QPS, 0.05x concurrency, ID 0x4C0C6A2C3174E3A8 at byte 414003819
# Scores: V/M = 0.02
# Time range: 2024-02-17T07:30:59 to 2024-02-17T07:32:00
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0      61
# Exec time      1      3s     7ms   131ms    46ms    91ms    29ms    46ms