11250604 - Githubissues

saza-ku commented 8 months ago

17000

saza-ku commented 8 months ago

isucon1

alp

+-------+--------+------------------------------------------+-------+-------+---------+-------+-------+
| COUNT | METHOD |                   URI                    |  MIN  |  MAX  |   SUM   |  AVG  |  P99  |
+-------+--------+------------------------------------------+-------+-------+---------+-------+-------+
| 9124  | GET    | /api/user/.+/icon                        | 0.004 | 0.264 | 164.168 | 0.018 | 0.108 |
| 1057  | GET    | /api/livestream/.+/livecomment           | 0.004 | 0.676 | 150.789 | 0.143 | 0.528 |
| 310   | GET    | /api/livestream/.+                       | 0.004 | 1.060 | 150.062 | 0.484 | 1.008 |
| 1088  | GET    | /api/livestream/.+/reaction              | 0.008 | 0.656 | 146.908 | 0.135 | 0.564 |
| 1094  | POST   | /api/livestream/.+/livecomment           | 0.004 | 0.260 | 63.677  | 0.058 | 0.168 |
| 529   | POST   | /api/register                            | 0.032 | 0.264 | 53.321  | 0.101 | 0.192 |
| 362   | POST   | /api/livestream/.+                       | 0.024 | 0.296 | 31.784  | 0.088 | 0.228 |
| 979   | POST   | /api/livestream/.+/reaction              | 0.004 | 0.268 | 29.868  | 0.031 | 0.124 |
| 555   | POST   | /api/icon                                | 0.004 | 0.268 | 16.249  | 0.029 | 0.144 |
| 269   | GET    | /api/livestream/.+/ngwords               | 0.004 | 0.208 | 10.801  | 0.040 | 0.168 |
| 534   | POST   | /api/login                               | 0.004 | 0.336 | 10.744  | 0.020 | 0.156 |
| 177   | GET    | /api/livestream                          | 0.004 | 0.180 | 10.564  | 0.060 | 0.156 |
| 361   | GET    | /api/livestream/.+/report                | 0.004 | 0.176 | 8.320   | 0.023 | 0.132 |
| 350   | GET    | /api/tag                                 | 0.004 | 0.160 | 7.676   | 0.022 | 0.132 |
| 190   | POST   | /api/livestream/.+/moderate              | 0.004 | 0.128 | 4.924   | 0.026 | 0.128 |
| 58    | POST   | /api/livestream/.+/livecomment/.+/report | 0.004 | 0.088 | 2.324   | 0.040 | 0.088 |
| 16    | GET    | /api/user/.+/statistics                  | 0.028 | 0.220 | 2.244   | 0.140 | 0.220 |
| 91    | POST   | /api/livestream/.+/enter                 | 0.004 | 0.176 | 2.224   | 0.024 | 0.176 |
| 14    | GET    | /api/user/.+/livestream                  | 0.052 | 0.208 | 1.472   | 0.105 | 0.208 |
| 80    | DELETE | /api/livestream/.+/exit                  | 0.004 | 0.128 | 1.148   | 0.014 | 0.128 |
| 5     | GET    | /api/livestream/.+/statistics            | 0.028 | 0.132 | 0.372   | 0.074 | 0.132 |
| 15    | GET    | /api/user/.+/theme                       | 0.004 | 0.024 | 0.176   | 0.012 | 0.024 |
| 4     | GET    | /api/user/.+                             | 0.000 | 0.004 | 0.008   | 0.002 | 0.004 |
| 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=1700892260482;before=1700892336521

pprof

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

saza-ku commented 8 months ago

isucon2

alp

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

slow query

Count: 33156  Time=0.00s (59s)  Lock=0.00s (0s)  Rows=0.1 (4282), 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: 23434  Time=0.00s (39s)  Lock=0.00s (0s)  Rows=0.5 (11845), 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: 40994  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: 527  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: 1054  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=0.5 (527), 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: 94755  Time=0.00s (1s)  Lock=0.00s (0s)  Rows=0.0 (0), isudns[isudns]@isucon1
  #

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

Count: 527  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: 527  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=1.0 (527), isudns[isudns]@isucon1
  select id,name,master,last_check,notified_serial,type,options,catalog,account from domains where name='S'

Count: 1054  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.9s user time, 70ms system time, 36.75M rss, 51.08M vsz
# Current date: Sat Nov 25 06:05:55 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 197.09k total, 20 unique, 2.37k QPS, 1.32x concurrency ________
# Time range: 2023-11-25T06:04:20 to 2023-11-25T06:05:43
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           109s     1us    10ms   554us     2ms   828us    89us
# Lock time          146ms       0     3ms       0     1us     8us     1us
# Rows sent         16.78k       0       1    0.09    0.99    0.28       0
# Rows examine      86.34M       0   1.76k  459.37   1.61k  697.14       0
# Query size        15.36M       5     219   81.70  151.03   48.84  112.70

# Profile
# Rank Query ID                      Response time Calls R/Call V/M   Item
# ==== ============================= ============= ===== ====== ===== ====
#    1 0x42EF7D7D98FBCC9723BF896E... 59.4644 54.4% 33156 0.0018  0.00 SELECT records
#    2 0x3D83BC87F3B3A00D571FFC81... 39.3481 36.0% 23434 0.0017  0.00 SELECT records
#    3 0x22279D81D51006139E0C7640...  4.9124  4.5% 40994 0.0001  0.00 SELECT domains domainmetadata
#    4 0x859BBB7E9D760686137A9444...  2.0601  1.9%   527 0.0039  0.00 DELETE records
# MISC 0xMISC                         3.5536  3.3% 98978 0.0000   0.0 <16 ITEMS>

# Query 1: 487.59 QPS, 0.87x concurrency, ID 0x42EF7D7D98FBCC9723BF896EBFC51D24 at byte 55420505
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T06:04:20 to 2023-11-25T06:05:28
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         16   33156
# Exec time     54     59s   698us    10ms     2ms     3ms   538us     2ms
# Lock time     29    43ms       0   368us     1us     1us     3us     1us
# Rows sent     24   4.18k       0       1    0.13    0.99    0.33       0
# Rows examine  57  49.23M   1.25k   1.76k   1.52k   1.69k  144.31   1.46k
# Query size    29   4.50M     129     219  142.25  158.58   12.12  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='*.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='*.u.isucon.dev' and domain_id=4"] at /usr/bin/pt-query-digest line 7796.

# Query 2: 344.62 QPS, 0.58x concurrency, ID 0x3D83BC87F3B3A00D571FFC8104A6E50C at byte 53724925
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T06:04:20 to 2023-11-25T06:05:28
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11   23434
# Exec time     35     39s   659us     9ms     2ms     3ms   521us     2ms
# Lock time     20    30ms       0   160us     1us     1us     2us     1us
# Rows sent     68  11.57k       0       1    0.51    0.99    0.50    0.99
# Rows examine  40  34.79M   1.25k   1.76k   1.52k   1.69k  144.37   1.46k
# Query size    19   3.04M     126     218  136.08  151.03   11.51  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='ptj6takh4t4649mqddwur0.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='ptj6takh4t4649mqddwur0.u.isucon.dev'"] at /usr/bin/pt-query-digest line 7796.

# Query 3: 602.85 QPS, 0.07x concurrency, ID 0x22279D81D51006139E0C76405B54C261 at byte 31900402
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T06:04:20 to 2023-11-25T06:05:28
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         20   40994
# Exec time      4      5s    72us     4ms   119us   152us    95us   103us
# Lock time     42    62ms       0   391us     1us     1us     3us     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    29   4.46M     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: 7.75 QPS, 0.03x concurrency, ID 0x859BBB7E9D760686137A944406874C4D at byte 17622495
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T06:04:20 to 2023-11-25T06:05:28
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0     527
# Exec time      1      2s     2ms     9ms     4ms     6ms   828us     4ms
# Lock time      5     9ms       0     3ms    16us     1us   150us     1us
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0 794.10k   1.25k   1.76k   1.51k   1.69k  149.43   1.46k
# Query size     0  44.09k      78      93   85.67   88.31    3.33   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='haruka031.u.isucon.dev' and type='A'\G
# Converted for EXPLAIN
# EXPLAIN 
select * from  records where domain_id=4 and name='haruka031.u.isucon.dev' and type='A'\G

netdata

http://localhost:19992/#menu_services;after=1700892260510;before=1700892340520

pprof

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

saza-ku / isucon13

11250604 #51

isucon1

alp

slow query

explain

netdata

pprof

isucon2

alp

slow query

explain

netdata

pprof