先週末にisucon11-prior(事前講習のハンズオン課題)をやったのでメモ
github.com
isucon.net
結果
- 使用言語:Ruby
- 初期スコア:1765
- 最終スコア:13226(8時間で出せたスコア)
- 感想戦後:15101
最終的なサーバ構成
スペックはいずれもc5.large
- front *1 兼DB x 1 *2
- AP*3 x 2
- bench x 1
コンテキスト
事前にやったこと:AMI作成
AMIの作り方は https://github.com/matsuu/vagrant-isucon11-prior がむっちゃ参考になりました。
github.com
作成手順
- ubuntu-focalでEC2インスタンスを作る
- マニュアル によれば演習時のインスタンスタイプは
c5.large
を想定してるらしいが、AMI作成時は関係ないのでスペック上げておけば時間短縮できる
- 参考:
c5.large
だと3のコマンド実行で15分くらいかかる
- ボリュームサイズはデフォルトの8GiBでOK
- ボリュームサイズを増やしすぎるとそのAMIから作るEC2インスタンスもそれに引きづられるのでむしろダメ
- 例:50GiBでAMIを作るとEC2インスタンスは50GiB以上じゃないと作れなくなる
- セキュリティグループで最低限22番ポートだけは開放する
- sshでログイン
ssh -i /path/to/ec2_key_pair.pem ubuntu@PUBLIC_IP
- EC2インスタンス内で https://github.com/matsuu/vagrant-isucon11-prior/blob/655df852ee1539e763b1fb82c0251a43d333c33a/Vagrantfile#L78-L91 を1行ずつ実行
- ログアウトしてAMIを作成開始
- AMIの作成後にEC2インスタンスを止めるか削除する
AMIから起動したEC2インスタンスへisuconユーザでログインする方法
ubuntuユーザでログイン後にauthorized_keysをコピーするのが楽
- ubuntuユーザでログイン
ssh -i /path/to/ec2_key_pair.pem ubuntu@PUBLIC_IP
- EC2インスタンス内で下記を実行
sudo cp /home/ubuntu/.ssh/authorized_keys /home/isucon/.ssh/authorized_keys
- isuconユーザでログイン
ssh -i /path/to/ec2_key_pair.pem isucon@PUBLIC_IP
8時間の素振りでやったこと一覧
- 時系列順
- 本番を想定して10〜18時で素振りをしてます
AMI起動してベンチ即実行
この時点ではbenchとAPが同一
10:12:14.150419 ERR: validation: invalid: overbooking at 01FCM7DTTC8C6Y3B4PVR073T4C
10:12:14.447652 score: 1765(1815 - 50) : pass
10:12:14.447664 deduction: 50 / timeout: 0
NewRelicやSentryを仕込む
11:28:15.032062 SCORE: create-schedule: 18
11:28:15.032074 SCORE: create-reservation: 1239
11:28:15.032086 SCORE: login: 235
11:28:15.032094 SCORE: signup: 234
11:28:15.032164 score: 1554(1654 - 100) : pass
11:28:15.032171 deduction: 100 / timeout: 0
APとDBとbenchを分離
この時点のAPサーバのAMIを作って、そのAMIからDBサーバを作成
11:46:06.535986 SCORE: login: 242
11:46:06.536002 SCORE: signup: 241
11:46:06.536005 SCORE: create-schedule: 19
11:46:06.536007 SCORE: create-reservation: 1298
11:46:06.536010 score: 1730(1730 - 0) : pass
11:46:06.536012 deduction: 0 / timeout: 0
pumaの設定調整
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/config/puma.rb を下記のように修正
root = File.expand_path('..', __dir__)
directory root
rackup File.join(root, 'config.ru')
bind 'tcp://0.0.0.0:9292'
environment ENV.fetch('RACK_ENV') { 'development' }
pidfile File.join(root, 'tmp', 'puma.pid')
threads 0, 32
workers 32
preload_app!
log_requests false
wait_for_less_busy_worker 0.005
nakayoshi_fork true
wait_for_less_busy_worker
と nakayoshi_fork
は下記参照
isucon.net
11:51:03.549932 SCORE: create-reservation: 1581
11:51:03.549946 SCORE: login: 292
11:51:03.549952 SCORE: signup: 291
11:51:03.549962 SCORE: create-schedule: 22
11:51:03.550041 score: 2092(2093 - 1) : pass
11:51:03.550050 deduction: 1 / timeout: 2
NewRelicの設定がうまく反映されていなかったので修正
12:03:43.493894 deduction: 0 / timeout: 1
12:03:55.091536 SCORE: login: 220
12:03:55.091551 SCORE: signup: 219
12:03:55.091554 SCORE: create-schedule: 17
12:03:55.091557 SCORE: create-reservation: 1157
12:03:55.091591 score: 1547(1547 - 0) : pass
12:03:55.091598 deduction: 0 / timeout: 1
get_reservationsのN+1を修正
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L46-L50 がN+1だったので下記のようにして1クエリでとれるように修正
def get_reservations(schedule)
sql = <<~SQL
SELECT
r.id AS reservation_id,
r.schedule_id AS reservation_schedule_id,
r.user_id AS reservation_user_id,
r.created_at AS reservation_created_at,
u.id AS user_id,
u.email AS user_email,
u.nickname AS user_nickname,
u.staff AS user_staff,
u.created_at AS user_created_at
FROM `reservations` AS r
INNER JOIN users u ON u.id = r.user_id
WHERE r.schedule_id = ?
SQL
rows = db.xquery(sql, schedule[:id])
reservations = rows.each_with_object([]) do |row, reservations|
reservation = {
id: row[:reservation_id],
schedule_id: row[:reservation_schedule_id],
user_id: row[:reservation_user_id],
created_at: row[:reservation_created_at],
}
reservation[:user] = {
id: row[:user_id],
email: row[:user_email],
nickname: row[:user_nickname],
staff: row[:user_staff],
created_at: row[:user_created_at],
}
reservation[:user][:email] = '' if !current_user || !current_user[:staff]
reservations << reservation
end
12:18:30.912796 SCORE: create-schedule: 18
12:18:30.912813 SCORE: create-reservation: 1294
12:18:30.912825 SCORE: login: 250
12:18:30.912832 SCORE: signup: 249
12:18:30.912839 score: 1724(1724 - 0) : pass
12:18:30.912846 deduction: 0 / timeout: 0
POST /api/reservationsのループを修正
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L149-L152 のループが無駄だったので下記のようにSQLでcountとるようにした
reserved = tx.xquery('SELECT COUNT(*) as cnt FROM `reservations` WHERE `schedule_id` = ?', schedule_id).first[:cnt].to_i
12:40:14.739025 SCORE: login: 272
12:40:14.739040 SCORE: signup: 271
12:40:14.739233 SCORE: create-schedule: 22
12:40:14.739238 SCORE: create-reservation: 1437
12:40:14.739271 score: 1929(1929 - 0) : pass
12:40:14.739277 deduction: 0 / timeout: 2
POST /api/reservationsでINSERT後にSELECTしてるのが無駄だったのでINSERT時にcreated_atを入れるようにした
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L156-L157 を
created_at = Time.now
tx.xquery('INSERT INTO `reservations` (`id`, `schedule_id`, `user_id`, `created_at`) VALUES (?, ?, ?, ?)', id, schedule_id, user_id, created_at)
のようにした
12:43:37.171543 SCORE: login: 242
12:43:37.171557 SCORE: create-schedule: 14
12:43:37.171567 SCORE: signup: 241
12:43:37.171570 SCORE: create-reservation: 1280
12:43:37.171576 score: 1662(1662 - 0) : pass
12:43:37.171585 deduction: 0 / timeout: 0
current_userのメモ化
NewRelic見てたらむっちゃusersへのSELECTが多くて気になって調べたら current_user
で毎回SELECTしてたのでメモ化した
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L42-L44 を
def current_user
@current_user ||= db.xquery('SELECT * FROM `users` WHERE `id` = ? LIMIT 1', session[:user_id]).first
end
のようにするだけでスコアが倍になって大爆笑した記憶
12:48:49.106668 SCORE: create-schedule: 38
12:48:49.106677 SCORE: signup: 492
12:48:49.106728 SCORE: create-reservation: 2604
12:48:49.106767 SCORE: login: 493
12:48:49.106930 score: 3326(3477 - 151) : pass
12:48:49.106938 deduction: 151 / timeout: 0
GET /api/schedules のN+1修正(不完全)
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L164-L167 のN+1を下記のように修正
sql = <<~SQL
SELECT
s.id AS id,
s.title AS title,
s.capacity AS capacity,
s.created_at AS created_at,
r.reserved AS reserved
FROM `schedules` AS s
INNER JOIN (
SELECT
schedule_id,
COUNT(*) AS reserved
FROM reservations
GROUP BY schedule_id
) r ON s.id = r.schedule_id
ORDER BY s.id DESC
SQL
schedules = db.xquery(sql)
スコアは増えてるんだけど同時にベンチマーカーでpanic出すようになって謎だった。この時点ではよくわからんのでそのまま進めた
13:00:14.156606 deduction: 0 / timeout: 4
13:00:17.157713 SCORE: create-schedule: 710
13:00:17.157731 SCORE: login: 7
13:00:17.157735 SCORE: signup: 6
13:00:17.157986 score: 7107(7107 - 0) : pass
13:00:17.157995 deduction: 0 / timeout: 4
panic: runtime error: index out of range [-1]
goroutine 75533 [running]:
main.(*Scenario).Validation.func1(0x7d08e8, 0xc0008d4420, 0xffffffffffffffff)
/home/isuadmin/src/isucon11-prior/benchmarker/scenario.go:304 +0xeec
github.com/isucon/isucandar/worker.(*Worker).processInfinity.func1(0x7d08e8, 0xc0008d4420)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/worker/worker.go:72 +0x46
github.com/isucon/isucandar/parallel.(*Parallel).Do.func1(0xc000a58d80, 0xc000312a80, 0x0)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:68 +0x73
created by github.com/isucon/isucandar/parallel.(*Parallel).Do
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:66 +0xa6
sinatraでindex.htmlを返さないようにした
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L182-L184 でsinatraで静的ファイルを読み込んで返しているのが無駄だったので、下記のようにnginxで返すようにした
location /initialize {
try_files $uri @webapp;
}
location /api/ {
try_files $uri @webapp;
}
location ^~ / {
}
13:16:12.892609 SCORE: signup: 6
13:16:12.892626 SCORE: login: 7
13:16:12.892631 SCORE: create-schedule: 855
13:16:12.893000 score: 8557(8557 - 0) : pass
13:16:12.893008 deduction: 0 / timeout: 5
panic: runtime error: index out of range [-1]
goroutine 185836 [running]:
main.(*Scenario).Validation.func1(0x7d08e8, 0xc0004a7440, 0xffffffffffffffff)
/home/isuadmin/src/isucon11-prior/benchmarker/scenario.go:304 +0xeec
github.com/isucon/isucandar/worker.(*Worker).processInfinity.func1(0x7d08e8, 0xc0004a7440)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/worker/worker.go:72 +0x46
github.com/isucon/isucandar/parallel.(*Parallel).Do.func1(0xc000bb8140, 0xc000c2a090, 0x0)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:68 +0x73
created by github.com/isucon/isucandar/parallel.(*Parallel).Do
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:66 +0xa6
generate_idでSELECTするのをやめた
マニュアル には
各エンドポイントの URI の変更は認められませんが、以下の点については明確に許可されます。
・ID 発行形式の変更
って書いてあったので https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L26-L32 でSELECTするのをやめて
def generate_id(table, tx)
SecureRandom.uuid
end
のように修正。(呼び出し元を変更するのが面倒だったので引数はそのまま)
ULIDからUUIDに変えた理由はよく覚えてない。
13:26:43.131061 SCORE: login: 7
13:26:43.131078 SCORE: signup: 6
13:26:43.131083 SCORE: create-schedule: 851
13:26:43.131215 score: 8517(8517 - 0) : pass
13:26:43.131220 deduction: 0 / timeout: 5
panic: runtime error: index out of range [-1]
goroutine 184194 [running]:
main.(*Scenario).Validation.func1(0x7d08e8, 0xc0004d1da0, 0xffffffffffffffff)
/home/isuadmin/src/isucon11-prior/benchmarker/scenario.go:304 +0xeec
github.com/isucon/isucandar/worker.(*Worker).processInfinity.func1(0x7d08e8, 0xc0004d1da0)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/worker/worker.go:72 +0x46
github.com/isucon/isucandar/parallel.(*Parallel).Do.func1(0xc0006135c0, 0xc000a23660, 0x0)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:68 +0x73
created by github.com/isucon/isucandar/parallel.(*Parallel).Do
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:66 +0xa6
POST /api/signupでINSERT後にSELECTするのをやめた
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L98-L99 にも POST /api/reservations
と同じ問題があったので
created_at = Time.now
tx.xquery('INSERT INTO `users` (`id`, `email`, `nickname`, `created_at`) VALUES (?, ?, ?, ?)', id, email, nickname, created_at)
のように修正
13:30:30.845231 SCORE: login: 7
13:30:30.845248 SCORE: signup: 6
13:30:30.845253 SCORE: create-schedule: 874
13:30:30.846415 score: 8735(8747 - 12) : pass
13:30:30.846424 deduction: 0 / timeout: 127
panic: runtime error: index out of range [-1]
goroutine 185720 [running]:
main.(*Scenario).Validation.func1(0x7d08e8, 0xc000181c80, 0xffffffffffffffff)
/home/isuadmin/src/isucon11-prior/benchmarker/scenario.go:304 +0xeec
github.com/isucon/isucandar/worker.(*Worker).processInfinity.func1(0x7d08e8, 0xc000181c80)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/worker/worker.go:72 +0x46
github.com/isucon/isucandar/parallel.(*Parallel).Do.func1(0xc000a2cd00, 0xc0009e7950, 0x0)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:68 +0x73
created by github.com/isucon/isucandar/parallel.(*Parallel).Do
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:66 +0xa6
netdataをDBサーバに流す
netdata が重いかもと思って、そんなに負荷の高くなかったDBサーバに流すようにしたけどそんなにスコア変わらなかった
13:39:49.441780 SCORE: create-schedule: 871
13:39:49.441799 SCORE: login: 7
13:39:49.441802 SCORE: signup: 6
13:39:49.442042 score: 8717(8717 - 0) : pass
13:39:49.442068 deduction: 0 / timeout: 4
panic: runtime error: index out of range [-1]
goroutine 185720 [running]:
main.(*Scenario).Validation.func1(0x7d08e8, 0xc000181c80, 0xffffffffffffffff)
/home/isuadmin/src/isucon11-prior/benchmarker/scenario.go:304 +0xeec
github.com/isucon/isucandar/worker.(*Worker).processInfinity.func1(0x7d08e8, 0xc000181c80)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/worker/worker.go:72 +0x46
github.com/isucon/isucandar/parallel.(*Parallel).Do.func1(0xc000a2cd00, 0xc0009e7950, 0x0)
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:68 +0x73
created by github.com/isucon/isucandar/parallel.(*Parallel).Do
/home/isuadmin/go/pkg/mod/github.com/isucon/isucandar@v0.0.0-20210609100057-baa52484de01/parallel/parallel.go:66 +0xa6
前の方にやった「GET /api/schedules のN+1修正(不完全)」をrevert
ずっとpanic出てるのもアレだったので本格的になおすためにいったんrevertした
13:48:51.002083 SCORE: create-schedule: 41
13:48:51.002098 SCORE: signup: 521
13:48:51.002111 SCORE: create-reservation: 2878
13:48:51.002120 SCORE: login: 522
13:48:51.002146 score: 3810(3810 - 0) : pass
13:48:51.002154 deduction: 0 / timeout: 1
GET /api/schedules のN+1修正(完全版)
最終的にこれでなおった。( INNER JOIN
を LEFT JOIN
に変えた)
sql = <<~SQL
SELECT
s.id AS id,
s.title AS title,
s.capacity AS capacity,
s.created_at AS created_at,
IFNULL(r.reserved, 0) AS reserved
FROM `schedules` AS s
LEFT JOIN (
SELECT
schedule_id,
COUNT(*) AS reserved
FROM reservations
GROUP BY schedule_id
) r ON s.id = r.schedule_id
ORDER BY s.id DESC
SQL
schedules = db.xquery(sql)
panicしてた時ほどスコアは増えなかったのでスコア8000はバグだったのか...
13:56:18.541470 SCORE: create-schedule: 40
13:56:18.541484 SCORE: create-reservation: 3265
13:56:18.541494 SCORE: login: 600
13:56:18.541497 SCORE: signup: 599
13:56:18.541607 score: 4262(4265 - 3) : pass
13:56:18.541614 deduction: 3 / timeout: 2
reservationsにindexつけた
ALTER TABLE reservations ADD INDEX schedule_id (`schedule_id`);
ALTER TABLE reservations ADD INDEX user_id (`user_id`);
14:09:07.199826 SCORE: create-reservation: 3352
14:09:07.199843 SCORE: login: 612
14:09:07.199847 SCORE: signup: 611
14:09:07.199853 SCORE: create-schedule: 45
14:09:07.199858 score: 4414(4414 - 0) : pass
14:09:07.199863 deduction: 0 / timeout: 0
ブログ書きながら気づいたんだけど https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L146 があったので schedule_id
と user_id
の複合indexでもよかったかも
POST /api/schedules でINSERT後にSELECTしないようにした
他エンドポイントで修正済のやつを見逃してたので https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L129-L130 を
created_at = Time.now
tx.xquery('INSERT INTO `schedules` (`id`, `title`, `capacity`, `created_at`) VALUES (?, ?, ?, ?)', id, title, capacity, created_at)
のようになおした
14:16:39.149303 SCORE: create-reservation: 3460
14:16:39.149331 SCORE: login: 626
14:16:39.149337 SCORE: signup: 625
14:16:39.149347 SCORE: create-schedule: 47
14:16:39.149420 score: 4555(4556 - 1) : pass
14:16:39.149428 deduction: 1 / timeout: 1
2台目のAP追加
14:27:18.376503 SCORE: login: 747
14:27:18.376518 SCORE: signup: 746
14:27:18.376523 SCORE: create-schedule: 55
14:27:18.376526 SCORE: create-reservation: 4102
14:27:18.376530 score: 5399(5399 - 0) : pass
14:27:18.376533 deduction: 0 / timeout: 0
このあとpumaのworkersとかthreadsを色々いじったがそんなに改善しなかった
DBとnginxを同居
この時点では
だったと思うんだけど(うろ覚え)、冒頭にも書いた通りDBの負荷がそんなに高くなかったのでfrontとDBを同居させて
のような構成にした
14:51:04.770444 SCORE: login: 619
14:51:04.770470 SCORE: signup: 618
14:51:04.770475 SCORE: create-schedule: 47
14:51:04.770480 SCORE: create-reservation: 3445
14:51:04.770488 score: 4534(4534 - 0) : pass
14:51:04.770491 deduction: 0 / timeout: 0
netdataを3台に増やした
14:59:57.771297 SCORE: login: 723
14:59:57.771312 SCORE: signup: 722
14:59:57.771323 SCORE: create-schedule: 53
14:59:57.771326 SCORE: create-reservation: 3903
14:59:57.771329 score: 5156(5156 - 0) : pass
14:59:57.771334 deduction: 0 / timeout: 0
parallelismを40にした
この時点で各サーバともCPU使用率50%前後止まりでスコアが伸び悩んでいたのでダメ元で -parallelism
(ベンチマーカーのパラメータ)を増やしたらスコアが増えた(が、timeoutも増えた...)
15:19:27.198058 SCORE: login: 462
15:19:27.198083 SCORE: signup: 461
15:19:27.198093 SCORE: create-schedule: 84
15:19:27.198100 SCORE: create-reservation: 4875
15:19:27.206160 score: 6059(6177 - 118) : pass
15:19:27.206173 deduction: 3 / timeout: 1154
設定調整祭
この辺でひたすらpumaやnginxの設定を調整しまくってた
parallelismを20に戻した
timeoutが多くてスコアが伸び悩んでそうだったのでダメ元でparallelismを20に戻したらスコアが改善した。どうして...(現場猫顔)
17:45:53.615559 SCORE: signup: 679
17:45:53.615574 SCORE: create-schedule: 98
17:45:53.615576 SCORE: create-reservation: 6925
17:45:53.615579 SCORE: login: 680
17:45:53.616384 score: 8550(8585 - 35) : pass
17:45:53.616392 deduction: 34 / timeout: 18
終了直前対応(その1)
nginxとmysqlのログを止めて、SentryとNewRelic(APMとinfra agentの両方)を無効化
17:51:08.566625 SCORE: login: 1093
17:51:08.566640 SCORE: signup: 1092
17:51:08.566650 SCORE: create-schedule: 138
17:51:08.566665 SCORE: create-reservation: 10580
17:51:08.566901 score: 13051(13053 - 2) : pass
17:51:08.566910 deduction: 1 / timeout: 16
puma設定修正
「NewRelic止めたからpumaのworker数増やせるのでは?」と思って増やしたらスコアが減った...
17:56:47.793917 SCORE: create-reservation: 10370
17:56:47.794019 SCORE: login: 1240
17:56:47.794073 SCORE: signup: 1239
17:56:47.794124 SCORE: create-schedule: 138
17:56:47.796378 score: 12725(12990 - 265) : pass
17:56:47.796530 deduction: 250 / timeout: 152
終了直前対応(その2)
pumaのworker数増やす設定をrevertして終了時間ギリギリでデプロイ
17:59:03.124528 SCORE: login: 1259
17:59:03.124632 SCORE: signup: 1258
17:59:03.124642 SCORE: create-schedule: 143
17:59:03.124651 SCORE: create-reservation: 10539
17:59:03.125527 score: 13226(13228 - 2) : pass
17:59:03.125539 deduction: 0 / timeout: 21
メトリクス見れるようにするために終了直前対応をrevertしてスコア計測
21:14:05.874582 SCORE: login: 952
21:14:05.874616 SCORE: signup: 951
21:14:05.874624 SCORE: create-schedule: 104
21:14:05.874630 SCORE: create-reservation: 6597
21:14:05.874955 score: 8585(8589 - 4) : pass
21:14:05.874963 deduction: 3 / timeout: 19
usersにemail index追加
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L110 で email
使ってるのにindex無いやんけって気づいてindex追加
ALTER TABLE users ADD INDEX email (`email`);
21:36:18.462310 SCORE: login: 848
21:36:18.462325 SCORE: signup: 847
21:36:18.462329 SCORE: create-schedule: 93
21:36:18.462332 SCORE: create-reservation: 7049
21:36:18.462454 score: 8826(8827 - 1) : pass
21:36:18.462465 deduction: 0 / timeout: 10
ActiveSupport::JSON
が重そうだったので https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L15 をojに変更
json_encoderをojに差し替える方法は下記を参考にした
qiita.com
21:57:01.325176 SCORE: login: 1044
21:57:01.325190 SCORE: signup: 1043
21:57:01.325201 SCORE: create-schedule: 119
21:57:01.325203 SCORE: create-reservation: 8102
21:57:01.325620 score: 10325(10336 - 11) : pass
21:57:01.325628 deduction: 10 / timeout: 18
再度終了直前対応
22:08:45.723600 SCORE: create-reservation: 12100
22:08:45.723613 SCORE: login: 1290
22:08:45.723615 SCORE: signup: 1289
22:08:45.723618 SCORE: create-schedule: 151
22:08:45.723879 score: 14899(14900 - 1) : pass
22:08:45.723887 deduction: 1 / timeout: 3
https://github.com/isucon/isucon11-prior/blob/aea2af2bdfdeab5905f60bdb79292b0ef44dd354/webapp/ruby/app.rb#L9 を見てて「sinatraのログ出力(出力先はsystemd)」も重そうだなあと思ってdisableにした
22:27:05.030386 SCORE: login: 1267
22:27:05.030401 SCORE: signup: 1266
22:27:05.030407 SCORE: create-schedule: 167
22:27:05.030412 SCORE: create-reservation: 12165
22:27:05.030627 score: 15101(15102 - 1) : pass
22:27:05.030632 deduction: 1 / timeout: 9
感想
1人チームなのでstakprofやalpみたいな手元で解析するツールは諦めて解析は全部NewRelicに任せてたんだけど、限界が出てきたのでそろそろstackprofくらいは使えるようにならないとなあという気持ちになってる