Open saza-ku opened 1 year ago
+-------+--------+-----+-----+-----+-----+-----+-----+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+-----+-----+-----+-----+-----+-----+
+-------+--------+-----+-----+-----+-----+-----+-----+
Count: 1 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), isudns[isudns]@localhost
SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED
Count: 1 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=0.0 (0), 0users@0hosts
administrator command: Quit
Reading from STDIN ...
# 120ms user time, 10ms system time, 36.00M rss, 50.43M vsz
# Current date: Sat Nov 25 02:19:57 2023
# Hostname: ip-192-168-0-13
# Files: STDIN
# Overall: 2 total, 2 unique, 0 QPS, 0x concurrency ______________________
# Time range: all events occurred at 2023-11-25T02:18:38
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 65us 3us 62us 32us 62us 41us 32us
# Lock time 0 0 0 0 0 0 0
# Rows sent 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0
# Query size 81 27 54 40.50 54 19.09 40.50
# Profile
# Rank Query ID Response time Calls R/Call V/M
# ==== ================================== ============= ===== ====== =====
# 1 0xB9AC05A7AE6C4E30B5B45F6F3CE05BE0 0.0001 95.4% 1 0.0001 0.00 SET
# 2 0xEDBC971AEC392917AA353644DE4C4CB4 0.0000 4.6% 1 0.0000 0.00 ADMIN QUIT
# Query 1: 0 QPS, 0x concurrency, ID 0xB9AC05A7AE6C4E30B5B45F6F3CE05BE0 at byte 0
# 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:18:38
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 50 1
# Exec time 95 62us 62us 62us 62us 62us 0 62us
# Lock time 0 0 0 0 0 0 0 0
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 66 54 54 54 54 54 0 54
# String:
# Databases isudns
# Hosts localhost
# Users isudns
# Query_time distribution
# 1us
# 10us ################################################################
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED\G
# Query 2: 0 QPS, 0x concurrency, ID 0xEDBC971AEC392917AA353644DE4C4CB4 at byte 269
# 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:18:38
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 50 1
# Exec time 4 3us 3us 3us 3us 3us 0 3us
# Lock time 0 0 0 0 0 0 0 0
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 33 27 27 27 27 27 0 27
# String:
# Databases isudns
# Hosts localhost
# Users isudns
# Query_time distribution
# 1us ################################################################
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
administrator command: Quit\G
http://localhost:19993/#menu_services;after=1700878717240;before=1700878797246
go tool pprof -http=0.0.0.0:1080 http://isucon3/pprof/11250218
+-------+--------+------------------------------------------+--------+--------+--------+--------+--------+
| COUNT | METHOD | URI | MIN | MAX | SUM | AVG | P99 |
+-------+--------+------------------------------------------+--------+--------+--------+--------+--------+
| 1 | POST | /api/initialize | 15.801 | 15.801 | 15.801 | 15.801 | 15.801 |
| 2 | GET | /api/livestream/.+/statistics | 6.948 | 7.064 | 14.012 | 7.006 | 7.064 |
| 2 | GET | /api/user/.+/statistics | 4.272 | 4.352 | 8.624 | 4.312 | 4.352 |
| 1 | POST | /api/livestream/.+ | 0.044 | 0.044 | 0.044 | 0.044 | 0.044 |
| 1 | POST | /api/register | 0.040 | 0.040 | 0.040 | 0.040 | 0.040 |
| 3 | POST | /api/livestream/.+/reaction | 0.012 | 0.012 | 0.036 | 0.012 | 0.012 |
| 2 | POST | /api/livestream/.+/livecomment | 0.016 | 0.016 | 0.032 | 0.016 | 0.016 |
| 2 | POST | /api/livestream/.+/livecomment/.+/report | 0.012 | 0.012 | 0.024 | 0.012 | 0.012 |
| 3 | POST | /api/login | 0.004 | 0.004 | 0.004 | 0.001 | 0.004 |
| 1 | POST | /api/livestream/.+/enter | 0.004 | 0.004 | 0.004 | 0.004 | 0.004 |
| 1 | GET | /api/payment | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
| 3 | GET | /api/tag | 0.000 | 0.000 | 0.000 | 0.000 | 0.000 |
+-------+--------+------------------------------------------+--------+--------+--------+--------+--------+
Count: 1000 Time=0.01s (6s) 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: 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: 14992 Time=0.00s (3s) 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 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.01s (3s) 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.01s (2s) Lock=0.00s (0s) Rows=0.0 (0), isucon[isucon]@localhost
INSERT INTO themes (user_id, dark_mode) VALUES (N, false)
Count: 69390 Time=0.00s (2s) Lock=0.00s (0s) Rows=0.5 (34106), 2users@localhost
#
Reading from STDIN ...
# 7.2s user time, 40ms system time, 43.36M rss, 58.17M vsz
# Current date: Sat Nov 25 02:20:05 2023
# Hostname: ip-192-168-0-12
# Files: STDIN
# Overall: 107.03k total, 77 unique, 1.32k QPS, 0.41x concurrency ________
# Time range: 2023-11-25T02:18:37 to 2023-11-25T02:19:58
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 33s 2us 464ms 312us 2ms 2ms 60us
# Lock time 38ms 0 70us 0 1us 0 0
# Rows sent 50.22k 0 7.32k 0.48 0.99 32.63 0
# Rows examine 36.58M 0 14.00k 358.32 964.41 552.41 0
# Query size 9.74M 5 1.94M 95.46 143.84 6.31k 31.70
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ============================= ============= ===== ====== ===== ====
# 1 0xDFFCC1D78939C4D781C7C583... 6.3832 19.1% 1000 0.0064 0.00 INSERT users
# 2 0xD2A0864774622BA36F655749... 5.8986 17.6% 1001 0.0059 0.00 INSERT themes
# 3 0xFD38427AE3D09E3883A680F7... 4.3622 13.0% 14992 0.0003 0.00 SELECT livestreams livecomments
# 4 0xF1B8EF06D6CA63B24BFF433E... 3.8907 11.6% 2000 0.0019 0.00 SELECT users livestreams livecomments
# MISC 0xMISC 12.9245 38.6% 88042 0.0001 0.0 <73 ITEMS>
# Query 1: 83.33 QPS, 0.53x concurrency, ID 0xDFFCC1D78939C4D781C7C58349101F50 at byte 279395
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:18:38 to 2023-11-25T02:18:50
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 1000
# Exec time 19 6s 3ms 62ms 6ms 9ms 2ms 6ms
# Lock time 2 1ms 0 11us 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 4 401.18k 192 463 410.81 420.77 16.87 400.73
# 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
INSERT INTO users (id, name, display_name, description, password) VALUES (317, 'katotaichi0', 'うさぎうさぎうさぎもち', '普段ウェディングプランナーをしています。\nよろしくおねがいします!\n\n連絡は以下からお願いします。\n\nウェブサイト: http://katotaichi.example.com/\nメールアドレス: katotaichi@example.com\n', '$2a$04$zoGEpfPL0Ypk8OengyTkvuOdM0QVy30SWsY1C7y1aBvWBICJYu51y')\G
# Query 2: 27.05 QPS, 0.16x concurrency, ID 0xD2A0864774622BA36F6557496405CF75 at byte 377882
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:18:38 to 2023-11-25T02:19:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 1001
# Exec time 17 6s 72us 21ms 6ms 8ms 974us 6ms
# Lock time 2 1ms 0 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 0 57.07k 55 60 58.38 56.92 0.19 56.92
# 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 'themes'\G
# SHOW CREATE TABLE `isupipe`.`themes`\G
INSERT INTO themes (user_id, dark_mode) VALUES (429, true)\G
# Query 3: 832.89 QPS, 0.24x concurrency, ID 0xFD38427AE3D09E3883A680F7BAF95D3A at byte 10787641
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:18:57 to 2023-11-25T02:19:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 14 14992
# Exec time 13 4s 264us 7ms 290us 301us 57us 273us
# Lock time 38 15ms 0 20us 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 17 1.71M 117 120 119.85 118.34 0.64 118.34
# 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 '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 = 2564\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: 133.33 QPS, 0.26x concurrency, ID 0xF1B8EF06D6CA63B24BFF433E06CCEB22 at byte 6475555
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2023-11-25T02:18:53 to 2023-11-25T02:19:08
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 1 2000
# Exec time 11 4s 2ms 5ms 2ms 2ms 134us 2ms
# Lock time 6 2ms 0 22us 1us 1us 0 1us
# Rows sent 3 1.95k 1 1 1 1 0 1
# Rows examine 10 3.82M 1.96k 1.96k 1.96k 1.96k 2 1.96k
# Query size 3 322.06k 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
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 = 851\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: 1003
# 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
http://localhost:19992/#menu_services;after=1700878717248;before=1700878797255
go tool pprof -http=0.0.0.0:1080 http://isucon2/pprof/11250218
isucon1
alp
slow query
explain
netdata
http://localhost:19991/#menu_services;after=1700878717307;before=1700878793326
pprof