saza-ku commented 8 months ago

75

saza-ku commented 8 months ago

isucon1

alp

+-------+--------+------------------------------------------+-------+-------+---------+-------+-------+
| COUNT | METHOD |                   URI                    |  MIN  |  MAX  |   SUM   |  AVG  |  P99  |
+-------+--------+------------------------------------------+-------+-------+---------+-------+-------+
| 404   | GET    | /api/livestream/.+                       | 0.004 | 1.112 | 188.088 | 0.466 | 1.048 |
| 3775  | GET    | /api/livestream/.+/livecomment           | 0.012 | 0.116 | 115.132 | 0.030 | 0.072 |
| 3809  | GET    | /api/livestream/.+/reaction              | 0.004 | 0.120 | 112.336 | 0.029 | 0.068 |
| 3575  | POST   | /api/livestream/.+/livecomment           | 0.000 | 0.108 | 94.760  | 0.027 | 0.072 |
| 3469  | POST   | /api/livestream/.+/reaction              | 0.004 | 0.132 | 82.912  | 0.024 | 0.064 |
| 34372 | GET    | /api/user/.+/icon                        | 0.000 | 0.044 | 60.364  | 0.002 | 0.008 |
| 552   | POST   | /api/register                            | 0.032 | 0.224 | 60.300  | 0.109 | 0.168 |
| 441   | POST   | /api/livestream/.+                       | 0.024 | 0.152 | 30.256  | 0.069 | 0.136 |
| 584   | POST   | /api/icon                                | 0.004 | 0.084 | 9.084   | 0.016 | 0.064 |
| 190   | GET    | /api/livestream                          | 0.004 | 0.132 | 8.788   | 0.046 | 0.124 |
| 556   | POST   | /api/login                               | 0.004 | 0.080 | 6.876   | 0.012 | 0.056 |
| 450   | GET    | /api/tag                                 | 0.004 | 0.092 | 5.720   | 0.013 | 0.052 |
| 220   | POST   | /api/livestream/.+/moderate              | 0.004 | 0.076 | 5.700   | 0.026 | 0.060 |
| 36    | GET    | /api/user/.+/statistics                  | 0.024 | 0.284 | 5.696   | 0.158 | 0.284 |
| 431   | GET    | /api/livestream/.+/report                | 0.004 | 0.076 | 4.952   | 0.011 | 0.052 |
| 314   | DELETE | /api/livestream/.+/exit                  | 0.004 | 0.100 | 3.628   | 0.012 | 0.064 |
| 323   | POST   | /api/livestream/.+/enter                 | 0.004 | 0.068 | 3.528   | 0.011 | 0.056 |
| 323   | GET    | /api/livestream/.+/ngwords               | 0.004 | 0.080 | 3.492   | 0.011 | 0.044 |
| 22    | GET    | /api/livestream/.+/statistics            | 0.028 | 0.188 | 2.696   | 0.123 | 0.188 |
| 33    | GET    | /api/user/.+/livestream                  | 0.044 | 0.136 | 2.556   | 0.077 | 0.136 |
| 58    | POST   | /api/livestream/.+/livecomment/.+/report | 0.004 | 0.100 | 1.680   | 0.029 | 0.100 |
| 35    | GET    | /api/user/.+/theme                       | 0.004 | 0.052 | 0.396   | 0.011 | 0.052 |
| 5     | GET    | /api/user/.+                             | 0.004 | 0.008 | 0.016   | 0.003 | 0.008 |
| 1     | GET    | /api/payment                             | 0.000 | 0.000 | 0.000   | 0.000 | 0.000 |
+-------+--------+------------------------------------------+-------+-------+---------+-------+-------+

slow query

explain

Reading from STDIN ...

# No events processed.

netdata

http://localhost:19991/#menu_services;after=1700896414245;before=1700896490263

pprof

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

saza-ku commented 8 months ago

isucon2

alp

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

slow query

Count: 32267  Time=0.00s (59s)  Lock=0.00s (0s)  Rows=0.2 (5620), isudns[isudns]@isucon1
  SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=N and name='S' and domain_id=N

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

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

Count: 550  Time=0.00s (2s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@isucon1
  delete from records where domain_id=N and name='S' and type='S'

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

Count: 96202  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@isucon1
  #

Count: 550  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@isucon1
  commit

Count: 550  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@isucon1
  insert into records (content,ttl,prio,type,domain_id,disabled,name,ordername,auth) values ('S',N,N,'S',N,N,'S',NULL,N)

Count: 550  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=1.0 (550), isudns[isudns]@isucon1
  select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'

Count: 1101  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@isucon1
  SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED

explain

Reading from STDIN ...

# 12.5s user time, 40ms system time, 36.75M rss, 51.07M vsz
# Current date: Sat Nov 25 07:15:09 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 196.08k total, 20 unique, 2.39k QPS, 1.34x concurrency ________
# Time range: 2023-11-25T07:13:34 to 2023-11-25T07:14:56
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           110s     1us    12ms   562us     2ms   857us    84us
# Lock time          159ms       0     4ms       0     1us    17us       0
# Rows sent         18.08k       0       1    0.09    0.99    0.29       0
# Rows examine      85.06M       0   1.79k  454.86   1.69k  696.23       0
# Query size        15.08M       5     223   80.64  151.03   48.76   51.63

# Profile
# Rank Query ID                     Response time Calls  R/Call V/M   Item
# ==== ============================ ============= ====== ====== ===== ====
#    1 0x42EF7D7D98FBCC9723BF896... 59.4636 54.0%  32267 0.0018  0.00 SELECT records
#    2 0x3D83BC87F3B3A00D571FFC8... 39.8099 36.1%  23301 0.0017  0.00 SELECT records
#    3 0x22279D81D51006139E0C764...  4.8915  4.4%  39348 0.0001  0.00 SELECT domains domainmetadata
#    4 0x859BBB7E9D760686137A944...  2.2758  2.1%    550 0.0041  0.00 DELETE records
# MISC 0xMISC                        3.7600  3.4% 100610 0.0000   0.0 <16 ITEMS>

# Query 1: 474.51 QPS, 0.87x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 27979783
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:13:34 to 2023-11-25T07:14:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         16   32267
# Exec time     53     59s   704us    11ms     2ms     3ms   601us     2ms
# Lock time     25    41ms       0    60us     1us     1us     1us     1us
# Rows sent     30   5.49k       0       1    0.17    0.99    0.38       0
# Rows examine  56  47.95M   1.25k   1.79k   1.52k   1.69k  150.20   1.46k
# Query size    28   4.37M     129     223  141.86  158.58   11.99  136.99
# String:
# Hosts        isucon1
# 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='6g2va4fplye0mg7towhos0.u.isucon.dev' and domain_id=4\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='6g2va4fplye0mg7towhos0.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.

# Query 2: 342.66 QPS, 0.59x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 33265607
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:13:34 to 2023-11-25T07:14:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11   23301
# Exec time     36     40s   660us     9ms     2ms     3ms   560us     2ms
# Lock time     20    33ms       0     2ms     1us     1us    13us     1us
# Rows sent     63  11.52k       0       1    0.51    0.99    0.50    0.99
# Rows examine  40  34.66M   1.25k   1.79k   1.52k   1.69k  150.16   1.46k
# Query size    19   3.01M     126     222  135.61  151.03   11.29  124.25
# String:
# Hosts        isucon1
# 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='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='u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.

# Query 3: 578.65 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 41157096
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:13:34 to 2023-11-25T07:14:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         20   39348
# Exec time      4      5s    71us     4ms   124us   159us   102us   103us
# Lock time     40    64ms       0     1ms     1us     1us    10us     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    28   4.28M     114     114     114     114       0     114
# String:
# Hosts        isucon1
# 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: 8.09 QPS, 0.03x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 24066544
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T07:13:34 to 2023-11-25T07:14:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     550
# Exec time      2      2s     2ms    12ms     4ms     7ms     1ms     4ms
# Lock time     11    19ms       0     4ms    34us     1us   293us     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0 834.93k   1.25k   1.79k   1.52k   1.69k  155.86   1.46k
# Query size     0  45.95k      78      93   85.55   88.31    3.41   84.10
# String:
# Hosts        isucon1
# 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
delete from records where domain_id=4 and name='babe0.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN 
select * from  records where domain_id=4 and name='babe0.u.isucon.dev' and type='A'\G

netdata

http://localhost:19992/#menu_services;after=1700896414245;before=1700896494253

pprof

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

saza-ku / isucon13

11250713 #73

75

isucon1

alp

slow query

explain

netdata

pprof

isucon2

alp

slow query

explain

netdata

pprof