search

k-nasa / ishocon2_yaru

0 stars 0 forks source link

計測ログ #2

Open k-nasa opened 4 years ago

k-nasa commented 4 years ago

bench

mysqldのCPU使用率が支配的。メモリに余裕は今んとこありあり

alp

COUNT 1XX 2XX 3XX 4XX 5XX METHOD URI MIN MAX SUM AVG P1 P50 P99 STDDEV MIN(BODY) MAX(BODY) SUM(BODY) AVG(BODY)
1 0 1 0 0 0 GET /initialize 0.372 0.372 0.372 0.372 0.372 0.372 0.372 0.000 6.000 6.000 6.000 6.000
113 0 113 0 0 0 GET /political_parties/* 0.004 0.172 13.964 0.124 0.004 0.088 0.108 0.023 1360.000 1486.000 160968.000 1424.496
341 0 341 0 0 0 GET / 0.048 0.172 41.800 0.123 0.140 0.132 0.104 0.023 7232.000 7265.000 2474782.000 7257.425
226 0 226 0 0 0 GET /candidates/\d+ 0.004 0.104 13.028 0.058 0.004 0.048 0.068 0.015 1145.000 1158.000 260038.000 1150.611
8457 0 8457 0 0 0 POST /vote 0.004 0.468 157.602 0.019 0.008 0.004 0.024 0.052 5256.000 5280.000 44554722.000 5268.384
676 0 676 0 0 0 GET /css/bootstrap.min.css 0.004 0.012 0.424 0.001 0.000 0.000 0.000 0.002 32526.000 122540.000 79293668.000 117298.325

slow log

# 25.3s user time, 200ms system time, 27.64M rss, 78.54M vsz
# Current date: Mon Sep  7 05:11:27 2020
# Hostname: ip-172-31-34-75
# Files: /var/log/mysql/slow.log
# Overall: 255.88k total, 14 unique, 3.76k QPS, 2.92x concurrency ________
# Time range: 2020-09-07T05:09:02 to 2020-09-07T05:10:10
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           199s     1us      2s   776us     2ms     9ms    73us
# Lock time             3s       0    13ms    12us    33us    63us       0
# Rows sent        283.05k       0      30    1.13    0.99    5.28       0
# Rows examine      40.20M       0  61.17k  164.73    0.99   2.91k       0
# Query size        14.17M      17     405   58.08  124.25   52.47   31.70

# Profile
# Rank Query ID           Response time  Calls  R/Call V/M   Item
# ==== ================== ============== ====== ====== ===== =============
#    1 0x9CD152A4DDC9722C 114.1775 57.4%  56066 0.0020  0.12 INSERT votes
#    2 0xD4A6C92C15F35370  53.4155 26.9%    502 0.1064  0.00 SELECT candidates votes
#    3 0x61B1A682CC26B92E  11.5880  5.8%    246 0.0471  0.00 SELECT votes
#    4 0x99AA0165670CE848   8.8132  4.4%  82058 0.0001  0.00 ADMIN PREPARE
#    5 0x72D4F3D4A71732AB   3.5214  1.8%   8457 0.0004  0.00 SELECT users
# MISC 0xMISC               7.2530  3.6% 108553 0.0001   0.0 <9 ITEMS>

# Query 1: 1.08k QPS, 2.20x concurrency, ID 0x9CD152A4DDC9722C at byte 66429190
# Scores: V/M = 0.12
# Time range: 2020-09-07T05:09:02 to 2020-09-07T05:09:54
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         21   56066
# Exec time     57    114s   491us      2s     2ms     3ms    16ms     2ms
# Lock time     57      2s    11us     2ms    32us    57us    74us    21us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    50   7.15M      79     405  133.64  234.30   64.68  118.34
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us
# 100us  ################
#   1ms  ################################################################
#  10ms  #
# 100ms  #
#    1s  #
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'votes'\G
#    SHOW CREATE TABLE `ishocon2`.`votes`\G
INSERT INTO votes (user_id, candidate_id, keyword) VALUES (3528173, 6, '他にまともな候補者がいないため')\G

# Query 2: 7.61 QPS, 0.81x concurrency, ID 0xD4A6C92C15F35370 at byte 67305984
# Scores: V/M = 0.00
# Time range: 2020-09-07T05:09:04 to 2020-09-07T05:10:10
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     502
# Exec time     26     53s   554us   187ms   106ms   134ms    22ms   105ms
# Lock time      4   131ms    75us    13ms   261us   273us   871us   131us
# Rows sent      5  14.71k      30      30      30      30       0      30
# Rows examine  66  26.82M     541  54.92k  54.71k  54.03k   3.37k  54.03k
# Query size     0 121.58k     248     248     248     248       0     248
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us
# 100us  #
#   1ms
#  10ms  ###########################
# 100ms  ################################################################
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'candidates'\G
#    SHOW CREATE TABLE `ishocon2`.`candidates`\G
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'votes'\G
#    SHOW CREATE TABLE `ishocon2`.`votes`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT c.id, c.name, c.political_party, c.sex, IFNULL(v.count, 0)
        FROM candidates AS c
        LEFT OUTER JOIN
        (SELECT candidate_id, COUNT(*) AS count
        FROM votes
        GROUP BY candidate_id) AS v
        ON c.id = v.candidate_id
        ORDER BY v.count DESC\G

# Query 3: 3.78 QPS, 0.18x concurrency, ID 0x61B1A682CC26B92E at byte 67208840
# Scores: V/M = 0.00
# Time range: 2020-09-07T05:09:04 to 2020-09-07T05:10:09
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     246
# Exec time      5     12s   144us   102ms    47ms    68ms    13ms    46ms
# Lock time      0     6ms    17us   107us    22us    40us     9us    19us
# Rows sent      0     246       1       1       1       1       0       1
# Rows examine  32  13.05M     367  54.75k  54.31k  54.03k   4.82k  54.03k
# Query size     0  14.10k      58      59   58.71   56.92       0   56.92
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us
# 100us  #
#   1ms
#  10ms  ################################################################
# 100ms  #
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'votes'\G
#    SHOW CREATE TABLE `ishocon2`.`votes`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(*) AS count FROM votes WHERE candidate_id = 2\G

# Query 4: 1.21k QPS, 0.13x concurrency, ID 0x99AA0165670CE848 at byte 67333143
# Scores: V/M = 0.00
# Time range: 2020-09-07T05:09:02 to 2020-09-07T05:10:10
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         32   82058
# Exec time      4      9s    30us     9ms   107us   260us   149us    66us
# 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    16   2.35M      30      30      30      30       0      30
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us  ################################################################
# 100us  ########################
#   1ms  #
#  10ms
# 100ms
#    1s
#  10s+
administrator command: Prepare\G

# Query 5: 162.63 QPS, 0.07x concurrency, ID 0x72D4F3D4A71732AB at byte 4228706
# Scores: V/M = 0.00
# Time range: 2020-09-07T05:09:02 to 2020-09-07T05:09:54
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          3    8457
# Exec time      1      4s    96us     7ms   416us     1ms   391us   247us
# Lock time     10   347ms    19us     3ms    41us    80us    62us    30us
# Rows sent      0   1.18k       0       1    0.14    0.99    0.35       0
# Rows examine   0   5.88k       0       1    0.71    0.99    0.45    0.99
# Query size     5 839.72k      89     122  101.68  107.34    7.39  102.22
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us  #
# 100us  ################################################################
#   1ms  ######
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'users'\G
#    SHOW CREATE TABLE `ishocon2`.`users`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM users WHERE name = 'タガミ タキコ' AND address = 'hoge' AND mynumber = '399314799'\G
k-nasa commented 4 years ago

インデックス貼ったあとのベンチ結果

alp

COUNT 1XX 2XX 3XX 4XX 5XX METHOD URI MIN MAX SUM AVG P1 P50 P99 STDDEV MIN(BODY) MAX(BODY) SUM(BODY) AVG(BODY)
1 0 1 0 0 0 GET /initialize 0.320 0.320 0.320 0.320 0.320 0.320 0.320 0.000 6.000 6.000 6.000 6.000
181 0 181 0 0 0 GET /political_parties/* 0.004 0.116 12.816 0.071 0.004 0.072 0.064 0.021 1360.000 1486.000 258260.000 1426.851
557 0 557 0 0 0 GET / 0.012 0.132 38.280 0.069 0.096 0.096 0.072 0.020 7222.000 7275.000 4047792.000 7267.131
9357 0 9357 0 0 0 POST /vote 0.004 2.440 162.664 0.017 0.008 0.004 0.048 0.061 5256.000 5280.000 49296804.000 5268.441
1026 0 1026 0 0 0 GET /candidates/\d+ 0.000 0.036 4.652 0.005 0.008 0.000 0.000 0.005 1145.000 1158.000 1180779.000 1150.857
1760 0 1760 0 0 0 GET /css/bootstrap.min.css 0.000 0.012 1.236 0.001 0.000 0.000 0.004 0.002 32526.000 122540.000 204972004.000 116461.366

slow

# 26.9s user time, 220ms system time, 27.61M rss, 78.58M vsz
# Current date: Mon Sep  7 06:10:19 2020
# Hostname: ip-172-31-34-75
# Files: /var/log/mysql/slow.log
# Overall: 269.68k total, 14 unique, 4.21k QPS, 2.80x concurrency ________
# Time range: 2020-09-07T06:08:32 to 2020-09-07T06:09:36
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           179s     2us      3s   664us     2ms     8ms    76us
# Lock time             4s       0     8ms    13us    36us    63us       0
# Rows sent        302.11k       0      30    1.15    0.99    5.30       0
# Rows examine      45.71M       0  62.22k  177.71    0.99   2.92k       0
# Query size        14.90M      17     405   57.95  143.84   51.45   31.70

# Profile
# Rank Query ID           Response time  Calls  R/Call V/M   Item
# ==== ================== ============== ====== ====== ===== =============
#    1 0x9CD152A4DDC9722C 107.4901 60.0%  57876 0.0019  0.05 INSERT votes
#    2 0xD4A6C92C15F35370  47.2044 26.3%    790 0.0598  0.01 SELECT candidates votes
#    3 0x99AA0165670CE848   9.5945  5.4%  86138 0.0001  0.00 ADMIN PREPARE
#    4 0x89D97A6B14A31CDD   2.7544  1.5%      1 2.7544  0.00 DELETE votes
#    5 0x2AA03DA038C300EE   2.6869  1.5%   8707 0.0003  0.00 SELECT candidates
#    6 0x72D4F3D4A71732AB   2.6181  1.5%   8707 0.0003  0.00 SELECT users
# MISC 0xMISC               6.8721  3.8% 107457 0.0001   0.0 <8 ITEMS>

# Query 1: 1.18k QPS, 2.19x concurrency, ID 0x9CD152A4DDC9722C at byte 28440376
# Scores: V/M = 0.05
# Time range: 2020-09-07T06:08:32 to 2020-09-07T06:09:21
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         21   57876
# Exec time     59    107s   477us      1s     2ms     3ms    10ms     2ms
# Lock time     56      2s    10us     6ms    34us    60us    87us    21us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    49   7.33M      79     405  132.86  234.30   61.82  118.34
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us
# 100us  #################
#   1ms  ################################################################
#  10ms  #
# 100ms
#    1s  #
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'votes'\G
#    SHOW CREATE TABLE `ishocon2`.`votes`\G
INSERT INTO votes (user_id, candidate_id, keyword) VALUES (277352, 21, '顔が好み')\G

# Query 2: 12.74 QPS, 0.76x concurrency, ID 0xD4A6C92C15F35370 at byte 70707407
# Scores: V/M = 0.01
# Time range: 2020-09-07T06:08:34 to 2020-09-07T06:09:36
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     790
# Exec time     26     47s   430us   145ms    60ms    91ms    18ms    59ms
# Lock time      5   188ms    69us     8ms   238us   657us   587us   108us
# Rows sent      7  23.14k      30      30      30      30       0      30
# Rows examine  95  43.58M     496  56.64k  56.49k  54.03k   2.69k  54.03k
# Query size     1 191.33k     248     248     248     248       0     248
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us
# 100us  #
#   1ms  #
#  10ms  ################################################################
# 100ms  ##
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'candidates'\G
#    SHOW CREATE TABLE `ishocon2`.`candidates`\G
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'votes'\G
#    SHOW CREATE TABLE `ishocon2`.`votes`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT c.id, c.name, c.political_party, c.sex, IFNULL(v.count, 0)
        FROM candidates AS c
        LEFT OUTER JOIN
        (SELECT candidate_id, COUNT(*) AS count
        FROM votes
        GROUP BY candidate_id) AS v
        ON c.id = v.candidate_id
        ORDER BY v.count DESC\G

# Query 3: 1.35k QPS, 0.15x concurrency, ID 0x99AA0165670CE848 at byte 69829558
# Scores: V/M = 0.00
# Time range: 2020-09-07T06:08:32 to 2020-09-07T06:09:36
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         31   86138
# Exec time      5     10s    32us    12ms   111us   273us   156us    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    16   2.46M      30      30      30      30       0      30
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us  ################################################################
# 100us  ##########################
#   1ms  #
#  10ms  #
# 100ms
#    1s
#  10s+
administrator command: Prepare\G

# Query 4: 0 QPS, 0x concurrency, ID 0x89D97A6B14A31CDD at byte 0 ________
# Scores: V/M = 0.00
# Time range: all events occurred at 2020-09-07T06:08:32
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0       1
# Exec time      1      3s      3s      3s      3s      3s       0      3s
# Lock time      0     5ms     5ms     5ms     5ms     5ms       0     5ms
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0  62.22k  62.22k  62.22k  62.22k  62.22k       0  62.22k
# Query size     0      17      17      17      17      17       0      17
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'votes'\G
#    SHOW CREATE TABLE `ishocon2`.`votes`\G
DELETE FROM votes\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select * from  votes\G

# Query 5: 177.69 QPS, 0.05x concurrency, ID 0x2AA03DA038C300EE at byte 55271644
# Scores: V/M = 0.00
# Time range: 2020-09-07T06:08:32 to 2020-09-07T06:09:21
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          3    8707
# Exec time      1      3s    84us     6ms   308us     1ms   371us   119us
# Lock time      9   332ms    20us     2ms    38us    73us    59us    28us
# Rows sent     84 255.09k      30      30      30      30       0      30
# Rows examine   0 255.09k      30      30      30      30       0      30
# Query size     1 204.07k      24      24      24      24       0      24
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us  ##################
# 100us  ################################################################
#   1ms  #######
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'candidates'\G
#    SHOW CREATE TABLE `ishocon2`.`candidates`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM candidates\G

# Query 6: 177.69 QPS, 0.05x concurrency, ID 0x72D4F3D4A71732AB at byte 12408547
# Scores: V/M = 0.00
# Time range: 2020-09-07T06:08:32 to 2020-09-07T06:09:21
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          3    8707
# Exec time      1      3s    97us    10ms   300us   690us   268us   236us
# Lock time     10   355ms    20us     2ms    40us    80us    50us    30us
# Rows sent      0   1.22k       0       1    0.14    0.99    0.35       0
# Rows examine   0   6.10k       0       1    0.72    0.99    0.45    0.99
# Query size     5 862.81k      89     122  101.47  107.34    7.45   97.36
# String:
# Databases    ishocon2
# Hosts        localhost
# Users        ishocon
# Query_time distribution
#   1us
#  10us  #
# 100us  ################################################################
#   1ms  #
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `ishocon2` LIKE 'users'\G
#    SHOW CREATE TABLE `ishocon2`.`users`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM users WHERE name = 'hoge' AND address = '徳島県' AND mynumber = '164558387'\G