search

saza-ku / isucon13

0 stars 0 forks source link

11250236 #13

Open saza-ku opened 7 months ago

saza-ku commented 7 months ago

isucon1

alp

+-------+--------+--------------------------------+-------+-------+-------+-------+-------+
| COUNT | METHOD |              URI               |  MIN  |  MAX  |  SUM  |  AVG  |  P99  |
+-------+--------+--------------------------------+-------+-------+-------+-------+-------+
| 3     | GET    | /api/user/.+                   | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 |
| 8     | GET    | /api/livestream/.+/livecomment | 0.000 | 0.004 | 0.004 | 0.001 | 0.004 |
| 1     | GET    | /api/tag                       | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 2     | GET    | /api/livestream/.+/statistics  | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 8     | GET    | /api/livestream/.+/reaction    | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 2     | GET    | /api/livestream/.+             | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+--------------------------------+-------+-------+-------+-------+-------+

slow query

Count: 56  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.8 (44), isudns[isudns]@localhost
  SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=N and name='S' and domain_id=N

Count: 52  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.5 (26), isudns[isudns]@localhost
  SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=N and type='S' and name='S'

Count: 60  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@localhost
  select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='S'

Count: 149  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@localhost
  #

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=103.0 (103), isucon[isucon]@localhost
  SELECT * FROM tags

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  START TRANSACTION

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  COMMIT

Count: 149  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), 0users@0hosts
  administrator command: Reset stmt

explain

Reading from STDIN ...

# 160ms user time, 20ms system time, 36.38M rss, 50.69M vsz
# Current date: Sat Nov 25 02:37:31 2023
# Hostname: ip-192-168-0-11
# Files: STDIN
# Overall: 327 total, 13 unique, 5.19 QPS, 0.00x concurrency _____________
# Time range: 2023-11-25T02:36:28 to 2023-11-25T02:37:31
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           91ms    11us     3ms   278us   725us   352us    89us
# Lock time          194us       0     4us       0     1us       0     1us
# Rows sent            177       0     103    0.54    0.99    5.65       0
# Rows examine     135.10k       0   1.25k  423.08   1.20k  578.69       0
# Query size        25.86k       6     195   80.97  136.99   47.38  112.70

# Profile
# Rank Query ID                        Response time Calls R/Call V/M   It
# ==== =============================== ============= ===== ====== ===== ==
#    1 0x42EF7D7D98FBCC9723BF896EBF...  0.0415 45.5%    56 0.0007  0.00 SELECT records
#    2 0x3D83BC87F3B3A00D571FFC8104...  0.0378 41.4%    52 0.0007  0.00 SELECT records
#    3 0x22279D81D51006139E0C76405B...  0.0058  6.4%    60 0.0001  0.00 SELECT domains domainmetadata
#    4 0xE77769C62EF669AA7DD5F6760F...  0.0037  4.1%     2 0.0019  0.00 SHOW VARIABLES
# MISC 0xMISC                           0.0024  2.7%   157 0.0000   0.0 <9 ITEMS>

# Query 1: 3.11 QPS, 0.00x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 64417
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:28 to 2023-11-25T02:36:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         17      56
# Exec time     45    41ms   710us     1ms   740us   725us    61us   725us
# Lock time     28    55us       0     1us       0     1us       0     1us
# Rows sent     24      44       0       1    0.79    0.99    0.41    0.99
# Rows examine  51  70.00k   1.25k   1.25k   1.25k   1.25k       0   1.25k
# Query size    28   7.38k     129     144  134.93  143.84    4.99  130.47
# String:
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  ##
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'records'\G
#    SHOW CREATE TABLE `records`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='pipe.u.isucon.dev' and domain_id=2\G
# EXPLAIN failed: DBD::mysql::st execute failed: Table 'isupipe.records' doesn't exist [for Statement "EXPLAIN SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='pipe.u.isucon.dev' and domain_id=2"] at /usr/bin/pt-query-digest line 7796.

# Query 2: 2.89 QPS, 0.00x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 79807
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:28 to 2023-11-25T02:36:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         15      52
# Exec time     41    38ms   674us     1ms   726us   881us    90us   690us
# Lock time     34    67us       0     4us     1us     1us       0     1us
# Rows sent     14      26       0       1    0.50    0.99    0.50    0.99
# Rows examine  48  65.00k   1.25k   1.25k   1.25k   1.25k       0   1.25k
# Query size    25   6.61k     126     143  130.19  136.99    4.67  124.25
# String:
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  #
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'records'\G
#    SHOW CREATE TABLE `records`\G
# EXPLAIN 
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and type='SOA' and name='pipe.u.isucon.dev'\G
# EXPLAIN failed: DBD::mysql::st execute failed: Table 'isupipe.records' doesn't exist [for Statement "EXPLAIN SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and type='SOA' and name='pipe.u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.

# Query 3: 3.33 QPS, 0.00x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 64991
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:28 to 2023-11-25T02:36:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         18      60
# Exec time      6     6ms    83us   128us    97us   113us     9us    93us
# Lock time     34    66us     1us     2us     1us     1us       0     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    25   6.68k     114     114     114     114       0     114
# String:
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us  ################################################################
# 100us  ###################
#   1ms
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'domains'\G
#    SHOW CREATE TABLE `domains`\G
#    SHOW TABLE STATUS LIKE 'domainmetadata'\G
#    SHOW CREATE TABLE `domainmetadata`\G
# EXPLAIN 
select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='u.isucon.dev'\G
# EXPLAIN failed: DBD::mysql::st execute failed: Table 'isupipe.domains' doesn't exist [for Statement "EXPLAIN select kind,content from domains, domainmetadata where domainmetadata.domain_id=domains.id and name='u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.

# Query 4: 0 QPS, 0x concurrency, ID 0xE77769C62EF669AA7DD5F6760F2D2EBB at byte 91404
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2023-11-25T02:37:31
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0       2
# Exec time      4     4ms   906us     3ms     2ms     3ms     1ms     2ms
# Lock time      1     3us     1us     2us     1us     2us       0     1us
# Rows sent      1       2       1       1       1       1       0       1
# Rows examine   0       2       1       1       1       1       0       1
# Query size     0      77      35      42   38.50      42    4.95   38.50
# String:
# Databases    isupipe
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  ################################################################
#  10ms
# 100ms
#    1s
#  10s+
SHOW VARIABLES LIKE 'wait\_timeout'\G

netdata

http://localhost:19991/#menu_services;after=1700879775371;before=1700879851525

pprof

go tool pprof -http=0.0.0.0:1080 http://isucon1/pprof/11250236
saza-ku commented 7 months ago

isucon3

alp

+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+

slow query

explain

Reading from STDIN ...

# No events processed.

netdata

http://localhost:19993/#menu_services;after=1700879775372;before=1700879855379

pprof

go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250236
saza-ku commented 7 months ago

isucon2

alp

+-------+--------+------------------------------------------+--------+--------+--------+--------+--------+
| COUNT | METHOD |                   URI                    |  MIN   |  MAX   |  SUM   |  AVG   |  P99   |
+-------+--------+------------------------------------------+--------+--------+--------+--------+--------+
| 1     | POST   | /api/initialize                          | 13.364 | 13.364 | 13.364 | 13.364 | 13.364 |
| 2     | GET    | /api/livestream/.+/statistics            | 5.588  | 5.660  | 11.248 | 5.624  | 5.660  |
| 2     | GET    | /api/user/.+/statistics                  | 3.240  | 3.252  | 6.492  | 3.246  | 3.252  |
| 1     | POST   | /api/register                            | 0.044  | 0.044  | 0.044  | 0.044  | 0.044  |
| 1     | POST   | /api/livestream/.+                       | 0.036  | 0.036  | 0.036  | 0.036  | 0.036  |
| 3     | POST   | /api/livestream/.+/reaction              | 0.008  | 0.012  | 0.032  | 0.011  | 0.012  |
| 2     | POST   | /api/livestream/.+/livecomment           | 0.012  | 0.016  | 0.028  | 0.014  | 0.016  |
| 2     | POST   | /api/livestream/.+/livecomment/.+/report | 0.012  | 0.012  | 0.024  | 0.012  | 0.012  |
| 1     | POST   | /api/livestream/.+/enter                 | 0.008  | 0.008  | 0.008  | 0.008  | 0.008  |
| 3     | POST   | /api/login                               | 0.000  | 0.004  | 0.004  | 0.001  | 0.004  |
| 3     | GET    | /api/tag                                 | 0.000  | 0.004  | 0.004  | 0.001  | 0.004  |
| 1     | GET    | /api/payment                             | 0.000  | 0.000  | 0.000  | 0.000  | 0.000  |
+-------+--------+------------------------------------------+--------+--------+--------+--------+--------+

slow query

Count: 1000  Time=0.01s (5s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  INSERT INTO users (id, name, display_name, description, password) VALUES (N, 'S', 'S', 'S', 'S')

Count: 14992  Time=0.00s (4s)  Lock=0.00s (0s)  Rows=1.0 (14992), isucon[isucon]@localhost
  SELECT IFNULL(SUM(l2.tip), N) FROM livestreams l INNER JOIN livecomments l2 ON l.id = l2.livestream_id WHERE l.id = N

Count: 14992  Time=0.00s (4s)  Lock=0.00s (0s)  Rows=1.0 (14992), isucon[isucon]@localhost
  SELECT COUNT(*) FROM livestreams l INNER JOIN reactions r ON l.id = r.livestream_id WHERE l.id = N

Count: 2000  Time=0.00s (3s)  Lock=0.00s (0s)  Rows=1.0 (2000), isucon[isucon]@localhost
  SELECT IFNULL(SUM(l2.tip), N) FROM users u
  INNER JOIN livestreams l ON l.user_id = u.id  
  INNER JOIN livecomments l2 ON l2.livestream_id = l.id
  WHERE u.id = N

Count: 2000  Time=0.00s (3s)  Lock=0.00s (0s)  Rows=1.0 (2000), isucon[isucon]@localhost
  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 = N

Count: 510  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  INSERT INTO themes (user_id, dark_mode) VALUES (N, true)

Count: 490  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  INSERT INTO themes (user_id, dark_mode) VALUES (N, false)

Count: 103  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  INSERT INTO tags(name) VALUES ('S')

explain

Reading from STDIN ...

# 2.9s user time, 40ms system time, 43.32M rss, 58.14M vsz
# Current date: Sat Nov 25 02:37:38 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 38.86k total, 78 unique, 479.73 QPS, 0.35x concurrency ________
# Time range: 2023-11-25T02:36:15 to 2023-11-25T02:37:36
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time            28s     1us   422ms   729us     4ms     3ms   316us
# Lock time           35ms       0    87us       0     1us       0     1us
# Rows sent         50.23k       0   7.32k    1.32    0.99   54.15    0.99
# Rows examine      36.61M       0  14.00k  987.85   1.96k  511.69  964.41
# Query size         7.70M       5   1.94M  207.78  158.58  10.47k  118.34

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0xDFFCC1D78939C4D781C7C583...  5.3250 18.8%  1000 0.0053  0.00 INSERT users
#    2 0xD2A0864774622BA36F655749...  4.9767 17.6%  1001 0.0050  0.00 INSERT themes
#    3 0xFD38427AE3D09E3883A680F7...  4.9355 17.4% 14992 0.0003  0.00 SELECT livestreams livecomments
#    4 0xC499D81D570D361DB61FC43A...  4.3197 15.2% 14992 0.0003  0.00 SELECT livestreams reactions
# MISC 0xMISC                         8.7900 31.0%  6873 0.0013   0.0 <74 ITEMS>

# Query 1: 100 QPS, 0.53x concurrency, ID 0xDFFCC1D78939C4D781C7C58349101F50 at byte 114582
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:16 to 2023-11-25T02:36:26
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          2    1000
# Exec time     18      5s     3ms    14ms     5ms     7ms   930us     5ms
# Lock time      3     1ms       0    12us     1us     1us       0     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     5 401.18k     192     463  410.81  420.77   16.87  400.73
# String:
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'users'\G
#    SHOW CREATE TABLE `users`\G
INSERT INTO users (id, name, display_name, description, password) VALUES (129, 'maayasasaki0', 'ちょっぴりちょこれーと', '普段営業をしています。\nよろしくおねがいします！\n\n連絡は以下からお願いします。\n\nウェブサイト: http://maayasasaki.example.com/\nメールアドレス: maayasasaki@example.com\n', '$2a$04$a2FyUeWJPpgE//4QaPNUSePy8ie9/KM46MavQwzvTx32r05ZE2vPC')\G

# Query 2: 33.37 QPS, 0.17x concurrency, ID 0xD2A0864774622BA36F6557496405CF75 at byte 114321
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:16 to 2023-11-25T02:36:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          2    1001
# Exec time     17      5s   109us    13ms     5ms     6ms   663us     5ms
# Lock time      3     1ms       0    10us     1us     1us       0     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size     0  57.07k      55      60   58.38   56.92    0.19   56.92
# String:
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us  #
#   1ms  ################################################################
#  10ms  #
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'themes'\G
#    SHOW CREATE TABLE `themes`\G
INSERT INTO themes (user_id, dark_mode) VALUES (128, false)\G

# Query 3: 1.07k QPS, 0.35x concurrency, ID 0xFD38427AE3D09E3883A680F7BAF95D3A at byte 8316893
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:32 to 2023-11-25T02:36:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         38   14992
# Exec time     17      5s   295us     7ms   329us   332us    67us   316us
# Lock time     38    14ms       0    17us       0     1us       0     1us
# Rows sent     29  14.64k       1       1       1       1       0       1
# Rows examine  39  14.33M    1001    1003    1002  964.41       0  964.41
# Query size    22   1.71M     117     120  119.85  118.34    0.64  118.34
# String:
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  #
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'livestreams'\G
#    SHOW CREATE TABLE `isupipe`.`livestreams`\G
#    SHOW TABLE STATUS FROM `isupipe` LIKE 'livecomments'\G
#    SHOW CREATE TABLE `isupipe`.`livecomments`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT IFNULL(SUM(l2.tip), 0) FROM livestreams l INNER JOIN livecomments l2 ON l.id = l2.livestream_id WHERE l.id = 4025\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: l
#    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: l2
#    partitions: NULL
#          type: ALL
# possible_keys: NULL
#           key: NULL
#       key_len: NULL
#           ref: NULL
#          rows: 1003
#      filtered: 10.00
#         Extra: Using where

# Query 4: 1.07k QPS, 0.31x concurrency, ID 0xC499D81D570D361DB61FC43A94BB888A at byte 8009921
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:36:32 to 2023-11-25T02:36:46
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         38   14992
# Exec time     15      4s   256us     3ms   288us   301us    36us   273us
# Lock time     37    13ms       0    87us       0     1us       0     1us
# Rows sent     29  14.64k       1       1       1       1       0       1
# Rows examine  39  14.33M    1001    1004 1002.50  964.41       0  964.41
# Query size    18   1.44M      98     101  100.85   97.36       0   97.36
# String:
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  #
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    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 
SELECT COUNT(*) FROM livestreams l INNER JOIN reactions r ON l.id = r.livestream_id WHERE l.id = 3539\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: l
#    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: r
#    partitions: NULL
#          type: ALL
# possible_keys: NULL
#           key: NULL
#       key_len: NULL
#           ref: NULL
#          rows: 1004
#      filtered: 10.00
#         Extra: Using where

netdata

http://localhost:19992/#menu_services;after=1700879775383;before=1700879855390

pprof

go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250236