11250251 - Githubissues

saza-ku commented 10 months ago

isucon1

alp

+-------+--------+-------------------------------+-------+-------+-------+-------+-------+
| COUNT | METHOD |              URI              |  MIN  |  MAX  |  SUM  |  AVG  |  P99  |
+-------+--------+-------------------------------+-------+-------+-------+-------+-------+
| 1     | GET    | /api/user/.+/statistics       | 5.068 | 5.068 | 5.068 | 5.068 | 5.068 |
| 1     | POST   | /api/livestream/.+            | 0.036 | 0.036 | 0.036 | 0.036 | 0.036 |
| 1     | GET    | /api/livestream/.+/statistics | 0.024 | 0.024 | 0.024 | 0.024 | 0.024 |
| 1     | GET    | /api/payment                  | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |
| 1     | POST   | /api/login                    | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+-------------------------------+-------+-------+-------+-------+-------+

slow query

Count: 1000  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=1.0 (1000), 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: 1000  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=1.0 (1000), 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: 39  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.8 (30), 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: 34  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.5 (17), 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: 1  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=7496.0 (7496), isucon[isucon]@localhost
  SELECT * FROM livestreams

Count: 7  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=1.0 (7), isucon[isucon]@localhost
  SELECT slot FROM reservation_slots WHERE start_at = N AND end_at = N

Count: 42  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: 1  Time=0.01s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  UPDATE reservation_slots SET slot = slot - N WHERE start_at >= N AND end_at <= N

explain

Reading from STDIN ...

# 330ms user time, 10ms system time, 36.75M rss, 51.07M vsz
# Current date: Sat Nov 25 02:52:28 2023
# Hostname: ip-192-168-0-11
# Files: STDIN
# Overall: 2.28k total, 35 unique, 30.03 QPS, 0.07x concurrency __________
# Time range: 2023-11-25T02:51:12 to 2023-11-25T02:52:28
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time             5s    11us    15ms     2ms     2ms   855us     2ms
# Lock time            3ms       0    23us     1us     1us     1us     1us
# Rows sent         11.26k       0   7.32k    5.05    0.99  159.08    0.99
# Rows examine       4.02M       0  10.71k   1.81k   1.86k  727.60   1.86k
# Query size       323.87k       6     381  145.33  158.58   31.16  143.84

# Profile
# Rank Query ID                       Response time Calls R/Call V/M   Ite
# ==== ============================== ============= ===== ====== ===== ===
#    1 0xF1B8EF06D6CA63B24BFF433E0...  2.4669 48.8%  1000 0.0025  0.00 SELECT users livestreams livecomments
#    2 0xDB74D52D39A7090F224C4DEEA...  2.4091 47.7%  1000 0.0024  0.00 SELECT users livestreams reactions
#    3 0x42EF7D7D98FBCC9723BF896EB...  0.0515  1.0%    39 0.0013  0.00 SELECT records
#    4 0x3D83BC87F3B3A00D571FFC810...  0.0426  0.8%    34 0.0013  0.00 SELECT records
# MISC 0xMISC                          0.0804  1.6%   209 0.0004   0.0 <31 ITEMS>

# Query 1: 200 QPS, 0.49x concurrency, ID 0xF1B8EF06D6CA63B24BFF433E06CCEB22 at byte 764036
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:51:12 to 2023-11-25T02:51:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         43    1000
# Exec time     48      2s     2ms    13ms     2ms     3ms   519us     2ms
# Lock time     45     1ms     1us    14us     1us     1us       0     1us
# Rows sent      8    1000       1       1       1       1       0       1
# Rows examine  47   1.91M   1.96k   1.96k   1.96k   1.96k       0   1.96k
# Query size    49 161.03k     163     166  164.89  158.58       0  158.58
# 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 'livecomments'\G
#    SHOW CREATE TABLE `isupipe`.`livecomments`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT IFNULL(SUM(l2.tip), 0) 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 = 969\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: u
#    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: 1001
#      filtered: 100.00
#         Extra: NULL
# *************************** 3. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: l
#    partitions: NULL
#          type: eq_ref
# possible_keys: PRIMARY
#           key: PRIMARY
#       key_len: 8
#           ref: isupipe.l2.livestream_id
#          rows: 1
#      filtered: 10.00
#         Extra: Using where

# Query 2: 200 QPS, 0.48x concurrency, ID 0xDB74D52D39A7090F224C4DEEAF3028C9 at byte 765126
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:51:12 to 2023-11-25T02:51:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         43    1000
# Exec time     47      2s     2ms    11ms     2ms     2ms   425us     2ms
# Lock time     46     1ms     1us    12us     1us     1us       0     1us
# Rows sent      8    1000       1       1       1       1       0       1
# Rows examine  47   1.91M   1.96k   1.96k   1.96k   1.96k       0   1.96k
# Query size    43 141.50k     143     146  144.89  143.84    0.65  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 
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 = 971\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: u
#    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: 1001
#      filtered: 100.00
#         Extra: NULL
# *************************** 3. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: l
#    partitions: NULL
#          type: eq_ref
# possible_keys: PRIMARY
#           key: PRIMARY
#       key_len: 8
#           ref: isupipe.r.livestream_id
#          rows: 1
#      filtered: 10.00
#         Extra: Using where

# Query 3: 7.80 QPS, 0.01x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 21552
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:51:12 to 2023-11-25T02:51:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1      39
# Exec time      1    52ms   716us     4ms     1ms     4ms   939us   839us
# Lock time      2    67us       0    23us     1us     1us     3us     1us
# Rows sent      0      30       0       1    0.77    0.99    0.42    0.99
# Rows examine   1  48.75k   1.25k   1.25k   1.25k   1.25k       0   1.25k
# Query size     1   5.19k     129     144  136.18  143.84    5.55  130.47
# String:
# Databases    isudns
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  ################################
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `1` LIKE 'records'\G
#    SHOW CREATE TABLE `1`.`records`\G
# EXPLAIN 
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='nntp.u.isucon.dev' and domain_id=3\G
# EXPLAIN failed: DBD::mysql::db do failed: Unknown database '1' [for Statement "USE `1`"] at /usr/bin/pt-query-digest line 7786.

# Query 4: 6.80 QPS, 0.01x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 22679
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:51:12 to 2023-11-25T02:51:17
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          1      34
# Exec time      0    43ms   675us     4ms     1ms     2ms   781us   903us
# Lock time      1    42us     1us     2us     1us     1us       0     1us
# Rows sent      0      17       0       1    0.50    0.99    0.50    0.99
# Rows examine   1  42.50k   1.25k   1.25k   1.25k   1.25k       0   1.25k
# Query size     1   4.35k     126     143  130.88  136.99    5.00  130.47
# String:
# Databases    isudns
# Hosts        localhost
# Users        isudns
# Query_time distribution
#   1us
#  10us
# 100us  ################################################################
#   1ms  ############################################
#  10ms
# 100ms
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `1` LIKE 'records'\G
#    SHOW CREATE TABLE `1`.`records`\G
# EXPLAIN 
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and type='SOA' and name='tcpmux.u.isucon.dev'\G
# EXPLAIN failed: DBD::mysql::db do failed: Unknown database '1' [for Statement "USE `1`"] at /usr/bin/pt-query-digest line 7786.

netdata

http://localhost:19991/#menu_services;after=1700880672054;before=1700880748508

pprof

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

saza-ku commented 10 months ago

isucon2

alp

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

slow query

explain

Reading from STDIN ...

# No events processed.

netdata

http://localhost:19992/#menu_services;after=1700880672043;before=1700880752049

pprof

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

saza-ku commented 10 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=1700880672044;before=1700880752050

pprof

go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250251

saza-ku / isucon13

11250251 #17

isucon1

alp

slow query

explain

netdata

pprof

isucon2

alp

slow query

explain

netdata

pprof

isucon3

alp

slow query

explain

netdata

pprof