分析-006(7875→8012)

[sunakan]

• https://github.com/sunakan/isunarabe13-suburi/issues/6

続き

スコア：7875

[sunakan]

make alp

alp json --sort sum -r -o count,method,uri,min,avg,max,sum --file tmp/analysis/latest/nginx-access.log.* -m '/api/user/\w+/statistics,/api/user/\w+/icon,/api/user/\w+/theme,/api/livestream/\d+/livecomment,/api/livestream/\d+/reaction,/api/livestream/\d+/moderate,/api/livestream/\d+/report,/api/livestream/\d+/ngwords,/api/livestream/\d+/exit,/api/livestream/\d+/enter,/api/livestream/\d+/statistics,/api/livestream/\d+'

+-------+--------+---------------------------------+--------+--------+--------+---------+
| COUNT | METHOD |               URI               |  MIN   |  AVG   |  MAX   |   SUM   |
+-------+--------+---------------------------------+--------+--------+--------+---------+
| 4155  | GET    | /api/user/\w+/icon              | 0.004  | 0.046  | 0.576  | 190.176 |
| 11    | GET    | /api/user/\w+/statistics        | 0.996  | 11.663 | 20.000 | 128.296 |
| 35    | POST   | /api/livestream/\d+/moderate    | 0.184  | 3.657  | 9.560  | 128.004 |
| 436   | GET    | /api/livestream/\d+/livecomment | 0.004  | 0.188  | 0.704  | 81.884  |
| 470   | GET    | /api/livestream/\d+/reaction    | 0.004  | 0.165  | 0.692  | 77.364  |
| 501   | POST   | /api/livestream/\d+/livecomment | 0.008  | 0.134  | 0.568  | 67.320  |
| 385   | POST   | /api/register                   | 0.008  | 0.130  | 0.464  | 49.976  |
| 123   | POST   | /api/livestream/reservation     | 0.144  | 0.404  | 0.952  | 49.720  |
| 68    | GET    | /api/livestream/search          | 0.040  | 0.650  | 1.560  | 44.200  |
| 384   | POST   | /api/icon                       | 0.012  | 0.091  | 0.568  | 34.860  |
| 407   | POST   | /api/livestream/\d+/reaction    | 0.004  | 0.068  | 0.384  | 27.600  |
| 390   | POST   | /api/login                      | 0.004  | 0.039  | 0.488  | 15.032  |
| 1     | POST   | /api/initialize                 | 13.796 | 13.796 | 13.796 | 13.796  |
| 2     | GET    | /api/livestream/\d+/statistics  | 3.956  | 4.032  | 4.108  | 8.064   |
| 106   | GET    | /api/tag                        | 0.004  | 0.049  | 0.380  | 5.204   |
| 196   | GET    | /api/livestream                 | 0.004  | 0.022  | 0.412  | 4.396   |
| 40    | GET    | /api/livestream/\d+/ngwords     | 0.004  | 0.099  | 0.212  | 3.976   |
| 54    | GET    | /api/livestream/\d+/report      | 0.008  | 0.047  | 0.304  | 2.520   |
| 46    | POST   | /api/livestream/\d+/enter       | 0.004  | 0.051  | 0.440  | 2.324   |
| 39    | DELETE | /api/livestream/\d+/exit        | 0.004  | 0.050  | 0.204  | 1.964   |
| 10    | GET    | /api/user/\w+/theme             | 0.008  | 0.019  | 0.056  | 0.192   |
| 1     | GET    | /api/user/test                  | 0.004  | 0.004  | 0.004  | 0.004   |
| 3     | GET    | /api/user/me                    | 0.004  | 0.001  | 0.004  | 0.004   |
| 1     | GET    | /api/livestream/\d+             | 0.004  | 0.004  | 0.004  | 0.004   |
| 1     | GET    | /api/payment                    | 0.000  | 0.000  | 0.000  | 0.000   |
+-------+--------+---------------------------------+--------+--------+--------+---------+

[sunakan]

make pt-query-digest

pt-query-digest --limit 10 tmp/analysis/latest/mysql-slow.log.*

# 17.5s user time, 100ms system time, 55.03M rss, 392.66G vsz
# Current date: Sun Sep 22 20:50:42 2024
# Hostname: 
# Files: tmp/analysis/latest/mysql-slow.log.isu-1, tmp/analysis/latest/mysql-slow.log.isu-2, tmp/analysis/latest/mysql-slow.log.isu-3
# Overall: 401.37k total, 94 unique, 3.79k QPS, 3.33x concurrency ________
# Time range: 2024-09-22T11:45:31 to 2024-09-22T11:47:17
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           353s     1us   423ms   878us     3ms     4ms   159us
# Lock time             1s       0    19ms     2us     1us    81us     1us
# Rows sent        319.22k       0   7.32k    0.81    0.99   22.22       0
# Rows examine      48.09M       0  14.03k  125.64  964.41  782.47    0.99
# Query size        68.83M       5   1.94M  179.81  329.68   3.89k   42.48

# Profile
# Rank Query ID                            Response time Calls  R/Call V/M
# ==== =================================== ============= ====== ====== ===
#    1 0xDB74D52D39A7090F224C4DEEAF3028C9  75.9284 21.5%   6822 0.0111  0.01 SELECT users livestreams reactions
#    2 0x4ADE2DC90689F1C4891749AF54FB8D14  44.9552 12.7%  55256 0.0008  0.00 DELETE SELECT livecomments
#    3 0x59F1B6DD8D9FEC059E55B3BFD624E8C3  22.5763  6.4%   1069 0.0211  0.01 SELECT reservation_slots
#    4 0x84B457C910C4A79FC9EBECB8B1065C66  20.1204  5.7%  22682 0.0009  0.00 SELECT icons
#    5 0x64CC8A4E8E4B390203375597CE4D611F  20.0181  5.7%    446 0.0449  0.01 SELECT ng_words
#    6 0xFFFCA4D67EA0A788813031B8BBC3B329  19.7748  5.6%   4052 0.0049  0.01 COMMIT
#    7 0xFBC5564AE716EAE82F20BFB45F6C37E7  18.8334  5.3%  46426 0.0004  0.00 SELECT tags
#    8 0x22279D81D51006139E0C76405B54C261  14.2813  4.0%  28674 0.0005  0.00 SELECT domains domainmetadata
#    9 0x42EF7D7D98FBCC9723BF896EBFC51D24  12.1607  3.4%  23116 0.0005  0.00 SELECT records
#   10 0x8F7679D452333ED3C7D60D22131CEFD4  10.3026  2.9%  68961 0.0001  0.00 ADMIN RESET STMT
# MISC 0xMISC                              93.7305 26.6% 143869 0.0007   0.0 <84 ITEMS>

# Query 1: 86.35 QPS, 0.96x concurrency, ID 0xDB74D52D39A7090F224C4DEEAF3028C9 at byte 146961708
# Scores: V/M = 0.01
# Time range: 2024-09-22T11:45:58 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1    6822
# Exec time     21     76s   191us    86ms    11ms    33ms    11ms     8ms
# Lock time      3    38ms       0    10ms     5us     1us   135us     1us
# Rows sent      2   6.66k       1       1       1       1       0       1
# Rows examine  30  14.51M       0   2.74k   2.18k   2.62k  226.09   2.06k
# Query size     1 964.91k     143     146  144.84  143.84    0.82  143.84
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us  #
#   1ms  ################################################################
#  10ms  ##################################################
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'users'\G
#    SHOW CREATE TABLE `isupipe`.`users`\G
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'livestreams'\G
#    SHOW CREATE TABLE `isupipe`.`livestreams`\G
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'reactions'\G
#    SHOW CREATE TABLE `isupipe`.`reactions`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(*) FROM users u
        INNER JOIN livestreams l ON l.user_id = u.id
        INNER JOIN reactions r ON r.livestream_id = l.id
        WHERE u.id = 30\G

# Query 2: 905.84 QPS, 0.74x concurrency, ID 0x4ADE2DC90689F1C4891749AF54FB8D14 at byte 47148191
# Scores: V/M = 0.00
# Time range: 2024-09-22T11:46:16 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         13   55256
# Exec time     12     45s    94us    34ms   813us     3ms     1ms   273us
# Lock time     15   172ms       0     9ms     3us     1us    64us     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0 107.94k       2       4    2.00    1.96    0.02    1.96
# Query size    25  17.48M     263     514  331.76  381.65   27.52  313.99
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us  #
# 100us  ################################################################
#   1ms  ###################
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'livecomments'\G
#    SHOW CREATE TABLE `isupipe`.`livecomments`\G
DELETE FROM livecomments
            WHERE
            id = 128 AND
            livestream_id = 7524 AND
            (SELECT COUNT(*)
            FROM
            (SELECT 'どちらのファンも満足の内容だった！' AS text) AS texts
            INNER JOIN
            (SELECT CONCAT('%', '空間機械学習', '%')  AS pattern) AS patterns
            ON texts.text LIKE patterns.pattern) >= 1\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select * from  livecomments
            WHERE
            id = 128 AND
            livestream_id = 7524 AND
            (SELECT COUNT(*)
            FROM
            (SELECT 'どちらのファンも満足の内容だった！' AS text) AS texts
            INNER JOIN
            (SELECT CONCAT('%', '空間機械学習', '%')  AS pattern) AS patterns
            ON texts.text LIKE patterns.pattern) >= 1\G

# Query 3: 13.53 QPS, 0.29x concurrency, ID 0x59F1B6DD8D9FEC059E55B3BFD624E8C3 at byte 69466534
# Scores: V/M = 0.01
# Time range: 2024-09-22T11:45:58 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0    1069
# Exec time      6     23s     2ms   103ms    21ms    48ms    14ms    17ms
# Lock time      0     6ms       0     2ms     5us     1us    73us     1us
# Rows sent      0   1.04k       1       1       1       1       0       1
# Rows examine  18   8.93M   8.55k   8.55k   8.55k   8.55k       0   8.55k
# Query size     0  89.78k      86      86      86      86       0      86
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  #####################
#  10ms  ################################################################
# 100ms  #
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'reservation_slots'\G
#    SHOW CREATE TABLE `isupipe`.`reservation_slots`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT slot FROM reservation_slots WHERE start_at = 1701154800 AND end_at = 1701158400\G

# Query 4: 287.11 QPS, 0.25x concurrency, ID 0x84B457C910C4A79FC9EBECB8B1065C66 at byte 118312208
# Scores: V/M = 0.00
# Time range: 2024-09-22T11:45:58 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          5   22682
# Exec time      5     20s    66us    45ms   887us     3ms     2ms   348us
# Lock time      6    66ms       0     3ms     2us     1us    42us     1us
# Rows sent      5  18.14k       0       1    0.82    0.99    0.38    0.99
# Rows examine   0  18.14k       0       1    0.82    0.99    0.38    0.99
# Query size     1 970.94k      41      44   43.83   42.48    0.25   42.48
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us  #####
# 100us  ################################################################
#   1ms  ######################
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'icons'\G
#    SHOW CREATE TABLE `isupipe`.`icons`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT image FROM icons WHERE user_id = 1014\G

# Query 5: 6.11 QPS, 0.27x concurrency, ID 0x64CC8A4E8E4B390203375597CE4D611F at byte 62254563
# Scores: V/M = 0.01
# Time range: 2024-09-22T11:46:04 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     446
# Exec time      5     20s     4ms    95ms    45ms    82ms    21ms    44ms
# Lock time      0   784us       0   114us     1us     1us     7us     1us
# Rows sent      0     164       0       3    0.37    1.96    0.65       0
# Rows examine  12   6.10M  14.00k  14.03k  14.02k  13.78k    0.00  13.78k
# Query size     0  43.12k      97      99   98.99   97.36    0.31   97.36
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ###
#  10ms  ################################################################
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'ng_words'\G
#    SHOW CREATE TABLE `isupipe`.`ng_words`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT id, user_id, livestream_id, word FROM ng_words WHERE user_id = 1025 AND livestream_id = 7537\G

# Query 6: 51.29 QPS, 0.25x concurrency, ID 0xFFFCA4D67EA0A788813031B8BBC3B329 at byte 140816652
# Scores: V/M = 0.01
# Time range: 2024-09-22T11:45:58 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1    4052
# Exec time      5     20s    20us    55ms     5ms    14ms     5ms     4ms
# 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     0  23.74k       6       6       6       6       0       6
# String:
# Databases    isupipe (3669/90%), isudns (383/9%)
# Hosts        localhost
# Users        isucon (3669/90%), isudns (383/9%)
# Query_time distribution
#   1us
#  10us  ###############################
# 100us  ##############
#   1ms  ################################################################
#  10ms  #################
# 100ms
#    1s
#  10s+
COMMIT\G

# Query 7: 692.93 QPS, 0.28x concurrency, ID 0xFBC5564AE716EAE82F20BFB45F6C37E7 at byte 148545569
# Scores: V/M = 0.00
# Time range: 2024-09-22T11:46:10 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11   46426
# Exec time      5     19s    49us    30ms   405us     1ms   796us   131us
# Lock time     15   167ms       0     5ms     3us     1us    64us     1us
# Rows sent     14  45.34k       1       1       1       1       0       1
# Rows examine   0  45.34k       1       1       1       1       0       1
# Query size     2   1.42M      31      33   31.96   31.70    0.46   31.70
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us  ################################################
# 100us  ################################################################
#   1ms  ###########
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'tags'\G
#    SHOW CREATE TABLE `isupipe`.`tags`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM tags WHERE id = 53\G

# Query 8: 308.32 QPS, 0.15x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 35449044
# Scores: V/M = 0.00
# Time range: 2024-09-22T11:45:44 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          7   28674
# Exec time      4     14s    86us    22ms   498us     2ms   875us   185us
# Lock time      8    94ms       0     6ms     3us     1us    51us     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     4   3.09M     113     113     113     113       0     113
# String:
# Databases    isudns
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us  #
# 100us  ################################################################
#   1ms  ########
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isudns` LIKE 'domains'\G
#    SHOW CREATE TABLE `isudns`.`domains`\G
#    SHOW TABLE STATUS FROM `isudns` LIKE 'domainmetadata'\G
#    SHOW CREATE TABLE `isudns`.`domainmetadata`\G
# EXPLAIN /*!50100 PARTITIONS*/
select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='t.isucon.pw'\G

# Query 9: 248.56 QPS, 0.13x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 151271379
# Scores: V/M = 0.00
# Time range: 2024-09-22T11:45:44 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          5   23116
# Exec time      3     12s    92us    20ms   526us     2ms   938us   194us
# Lock time      5    57ms       0     3ms     2us     1us    31us     1us
# Rows sent      0   2.42k       0       1    0.11    0.99    0.31       0
# Rows examine   0   2.42k       0       1    0.11    0.99    0.31       0
# Query size     4   3.12M     128     220  141.46  151.03   11.89  136.99
# String:
# Databases    isudns
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us  #
# 100us  ################################################################
#   1ms  #########
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isudns` LIKE 'records'\G
#    SHOW CREATE TABLE `isudns`.`records`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='*.t.isucon.pw' and domain_id=1\G

# Query 10: 741.52 QPS, 0.11x concurrency, ID 0x8F7679D452333ED3C7D60D22131CEFD4 at byte 140187682
# Scores: V/M = 0.00
# Time range: 2024-09-22T11:45:44 to 2024-09-22T11:47:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17   68961
# Exec time      2     10s     9us    22ms   149us   515us   503us    42us
# 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     3   2.17M      33      33      33      33       0      33
# String:
# Databases    isudns
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us  #
#  10us  ################################################################
# 100us  ###############
#   1ms  ##
#  10ms  #
# 100ms
#    1s
#  10s+
administrator command: Reset stmt\G

[sunakan]

SELECT COUNT(*) FROM users u
        INNER JOIN livestreams l ON l.user_id = u.id
        INNER JOIN reactions r ON r.livestream_id = l.id
        WHERE u.id = 30\G

これの実行計画を調べる

explain SELECT COUNT(*) FROM users INNER JOIN livestreams ON livestreams.user_id = users.id INNER JOIN reactions ON reactions.livestream_id = livestreams.id WHERE users.id = 30\G

*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: users
   partitions: NULL
         type: const
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 8
          ref: const
         rows: 1
     filtered: 100.00
        Extra: Using index
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: reactions
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 1407
     filtered: 100.00
        Extra: NULL
*************************** 3. row ***************************
           id: 1
  select_type: SIMPLE
        table: livestreams
   partitions: NULL
         type: eq_ref
possible_keys: PRIMARY,user_id_idx
          key: PRIMARY
      key_len: 8
          ref: isupipe.reactions.livestream_id
         rows: 1
     filtered: 5.00
        Extra: Using where
3 rows in set, 1 warning (0.00 sec)

[sunakan]

livestreamsテーブルとreactionsテーブルのインデックスを見てみる

livestreamsでは、user_id_idxもあるし、不要そう

多分reactionsテーブルのインデックスを貼れば良さそう

[sunakan]

alter table reactions add index livestream_id_idx (livestream_id);

cat tmp/db-servers | xargs -I{} ssh {} "sudo mysql isupipe -e 'alter table reactions add index livestream_id_idx (livestream_id);'"

[sunakan]

実行計画もいい感じそう

*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: users
   partitions: NULL
         type: const
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 8
          ref: const
         rows: 1
     filtered: 100.00
        Extra: Using index
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: livestreams
   partitions: NULL
         type: ref
possible_keys: PRIMARY,user_id_idx
          key: user_id_idx
      key_len: 8
          ref: const
         rows: 8
     filtered: 100.00
        Extra: Using index
*************************** 3. row ***************************
           id: 1
  select_type: SIMPLE
        table: reactions
   partitions: NULL
         type: ref
possible_keys: livestream_id_idx
          key: livestream_id_idx
      key_len: 8
          ref: isupipe.livestreams.id
         rows: 1
     filtered: 100.00
        Extra: Using index
3 rows in set, 1 warning (0.00 sec)

[sunakan]

スコア：8012

少し上がった（誤差の可能性あり）