11250310 - Githubissues

saza-ku commented 1 year 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=1700881821524;before=1700881901532

pprof

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

saza-ku commented 1 year 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=1700881821512;before=1700881901521

pprof

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

saza-ku commented 1 year ago

isucon1

alp

+-------+--------+------------------------------------------+-------+--------+---------+--------+--------+
| COUNT | METHOD |                   URI                    |  MIN  |  MAX   |   SUM   |  AVG   |  P99   |
+-------+--------+------------------------------------------+-------+--------+---------+--------+--------+
| 1913  | GET    | /api/user/.+/icon                        | 0.004 | 1.524  | 154.471 | 0.081  | 0.532  |
| 53    | GET    | /api/livestream/.+                       | 0.008 | 6.064  | 132.702 | 2.504  | 6.064  |
| 229   | GET    | /api/livestream/.+/livecomment           | 0.004 | 2.456  | 123.543 | 0.539  | 1.672  |
| 263   | GET    | /api/livestream/.+/reaction              | 0.004 | 1.788  | 106.762 | 0.406  | 1.668  |
| 6     | GET    | /api/user/.+/statistics                  | 3.164 | 20.001 | 84.265  | 14.044 | 20.001 |
| 247   | POST   | /api/livestream/.+/livecomment           | 0.008 | 0.816  | 51.572  | 0.209  | 0.640  |
| 210   | POST   | /api/register                            | 0.008 | 1.272  | 46.580  | 0.222  | 1.016  |
| 97    | POST   | /api/livestream/.+                       | 0.300 | 1.072  | 45.669  | 0.471  | 1.072  |
| 20    | POST   | /api/livestream/.+/moderate              | 0.192 | 3.848  | 40.021  | 2.001  | 3.848  |
| 220   | POST   | /api/livestream/.+/reaction              | 0.008 | 0.660  | 32.997  | 0.150  | 0.540  |
| 207   | POST   | /api/icon                                | 0.012 | 0.660  | 30.460  | 0.147  | 0.592  |
| 215   | POST   | /api/login                               | 0.004 | 0.576  | 16.882  | 0.079  | 0.460  |
| 80    | GET    | /api/livestream                          | 0.012 | 0.752  | 12.232  | 0.153  | 0.752  |
| 47    | POST   | /api/livestream/.+/livecomment/.+/report | 0.012 | 0.692  | 10.352  | 0.220  | 0.692  |
| 31    | GET    | /api/livestream/.+/ngwords               | 0.004 | 0.732  | 6.560   | 0.212  | 0.732  |
| 43    | GET    | /api/livestream/.+/report                | 0.004 | 0.924  | 5.632   | 0.131  | 0.924  |
| 75    | GET    | /api/tag                                 | 0.004 | 0.480  | 5.488   | 0.073  | 0.480  |
| 24    | POST   | /api/livestream/.+/enter                 | 0.004 | 0.416  | 1.924   | 0.080  | 0.416  |
| 15    | DELETE | /api/livestream/.+/exit                  | 0.008 | 0.144  | 0.732   | 0.049  | 0.144  |
| 5     | GET    | /api/user/.+/theme                       | 0.016 | 0.232  | 0.336   | 0.067  | 0.232  |
| 2     | GET    | /api/livestream/.+/statistics            | 0.032 | 0.036  | 0.068   | 0.034  | 0.036  |
| 4     | GET    | /api/user/.+                             | 0.000 | 0.004  | 0.004   | 0.001  | 0.004  |
| 1     | GET    | /api/payment                             | 0.004 | 0.004  | 0.004   | 0.004  | 0.004  |
+-------+--------+------------------------------------------+-------+--------+---------+--------+--------+

slow query

Count: 6556  Time=0.03s (170s)  Lock=0.00s (0s)  Rows=3.8 (24873), isucon[isucon]@localhost
  SELECT * FROM livestream_tags WHERE livestream_id = N

Count: 11815  Time=0.01s (60s)  Lock=0.00s (0s)  Rows=0.8 (9172), isucon[isucon]@localhost
  SELECT image FROM icons WHERE user_id = N

Count: 6826  Time=0.01s (52s)  Lock=0.00s (0s)  Rows=0.2 (1396), 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: 3577  Time=0.01s (34s)  Lock=0.00s (0s)  Rows=1.0 (3577), 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: 3578  Time=0.01s (33s)  Lock=0.00s (0s)  Rows=1.0 (3578), 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: 5039  Time=0.01s (27s)  Lock=0.00s (0s)  Rows=0.5 (2601), 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: 9908  Time=0.00s (21s)  Lock=0.00s (0s)  Rows=1.0 (9908), isucon[isucon]@localhost
  SELECT * FROM themes WHERE user_id = N

Count: 23023  Time=0.00s (19s)  Lock=0.00s (0s)  Rows=0.0 (0), isucon[isucon]@localhost
  DELETE FROM livecomments
  WHERE

explain

Reading from STDIN ...

# 11.5s user time, 70ms system time, 38.93M rss, 53.43M vsz
# Current date: Sat Nov 25 03:11:53 2023
# Hostname: ip-192-168-0-11
# Files: STDIN
# Overall: 157.63k total, 78 unique, 1.95k QPS, 6.52x concurrency ________
# Time range: 2023-11-25T03:10:21 to 2023-11-25T03:11:42
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           528s     1us   231ms     3ms    19ms     8ms   366us
# Lock time          848ms       0    56ms     5us     1us   247us     1us
# Rows sent        157.72k       0   7.32k    1.02    0.99   30.70    0.99
# Rows examine     125.87M       0  14.02k  837.34   7.31k   2.30k    0.99
# Query size        28.79M       5 175.32k  191.55  329.68   2.52k   40.45

# Profile
# Rank Query ID                     Response time  Calls  R/Call V/M   Ite
# ==== ============================ ============== ====== ====== ===== ===
#    1 0xF7144185D9A142A426A36DC... 170.1493 32.2%   6556 0.0260  0.01 SELECT livestream_tags
#    2 0x84B457C910C4A79FC9EBECB...  60.6581 11.5%  11815 0.0051  0.01 SELECT icons
#    3 0x42EF7D7D98FBCC9723BF896...  52.3534  9.9%   6826 0.0077  0.00 SELECT records
#    4 0xF1B8EF06D6CA63B24BFF433...  34.6160  6.6%   3577 0.0097  0.01 SELECT users livestreams livecomments
# MISC 0xMISC                       210.3494 39.8% 128852 0.0016   0.0 <74 ITEMS>

# Query 1: 85.14 QPS, 2.21x concurrency, ID 0xF7144185D9A142A426A36DC55C1D2623 at byte 18806948
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2023-11-25T03:10:21 to 2023-11-25T03:11:38
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          4    6556
# Exec time     32    170s     2ms    85ms    26ms    51ms    16ms    27ms
# Lock time      2    20ms       0     5ms     3us     1us    78us     1us
# Rows sent     15  24.29k       0      11    3.79    4.96    1.79    4.96
# Rows examine  55  69.71M  10.71k  11.09k  10.89k  10.80k  193.50  10.80k
# Query size     1 358.32k      53      56   55.97   54.21    0.14   54.21
# 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 'livestream_tags'\G
#    SHOW CREATE TABLE `isupipe`.`livestream_tags`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM livestream_tags WHERE livestream_id = 7526\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: livestream_tags
#    partitions: NULL
#          type: ALL
# possible_keys: NULL
#           key: NULL
#       key_len: NULL
#           ref: NULL
#          rows: 11027
#      filtered: 10.00
#         Extra: Using where

# Query 2: 153.44 QPS, 0.79x concurrency, ID 0x84B457C910C4A79FC9EBECB8B1065C66 at byte 20064146
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2023-11-25T03:10:21 to 2023-11-25T03:11:38
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          7   11815
# Exec time     11     61s    64us    47ms     5ms    16ms     6ms     3ms
# Lock time      8    73ms       0    16ms     6us     1us   170us     1us
# Rows sent      5   8.96k       0       1    0.78    0.99    0.41    0.99
# Rows examine   0   1.09M       0     199   96.30  183.58   59.03   92.72
# Query size     1 505.37k      41      44   43.80   42.48    0.28   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 
SELECT image FROM icons WHERE user_id = 1022\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: icons
#    partitions: NULL
#          type: ALL
# possible_keys: NULL
#           key: NULL
#       key_len: NULL
#           ref: NULL
#          rows: 200
#      filtered: 10.00
#         Extra: Using where

# Query 3: 88.65 QPS, 0.68x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 5926024
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T03:10:21 to 2023-11-25T03:11:38
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          4    6826
# Exec time      9     52s   716us    55ms     8ms    19ms     6ms     6ms
# Lock time      2    25ms       0     5ms     3us     1us    66us     1us
# Rows sent      0   1.36k       0       1    0.20    0.99    0.40       0
# Rows examine   7   9.10M   1.25k   1.45k   1.37k   1.39k   53.49   1.33k
# Query size     3 942.41k     129     213  141.38  158.58   11.60  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 
SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='c3d3iob5si8h7kcw10mu60.5io4l5qrrmr3n7bywa5q420.u.isucon.dev' and domain_id=4\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: records
#    partitions: NULL
#          type: ALL
# possible_keys: domain_id
#           key: NULL
#       key_len: NULL
#           ref: NULL
#          rows: 1487
#      filtered: 1.00
#         Extra: Using where

# Query 4: 46.45 QPS, 0.45x concurrency, ID 0xF1B8EF06D6CA63B24BFF433E06CCEB22 at byte 62609354
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2023-11-25T03:10:21 to 2023-11-25T03:11:38
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          2    3577
# Exec time      6     35s     1ms    93ms    10ms    33ms    11ms     2ms
# Lock time      0     8ms       0   664us     2us     1us    18us     1us
# Rows sent      2   3.49k       1       1       1       1       0       1
# Rows examine   5   7.17M   1.96k   2.31k   2.05k   2.27k  128.32   1.96k
# Query size     1 575.74k     163     166  164.82  158.58    0.00  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 
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 = 330\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: 1244
#      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

netdata

http://localhost:19991/#menu_services;after=1700881821526;before=1700881897766

pprof

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

moririn2528 commented 1 year ago

3864

saza-ku / isucon13

11250310 #21

isucon3

alp

slow query

explain

netdata

pprof

isucon2

alp

slow query

explain

netdata

pprof

isucon1

alp

slow query

explain

netdata

pprof