private-isuで70万点取るためにやったこと

この記事ははてなエンジニア Advent Calendar 2023の17日目の記事です。

ついでにISUBONの17日目の記事です。スコアは変わらず717,858点。

今月の初めからISUBON(Iikanjini Speed Up BlogathON)と称してprivate-isuで遊んでいる。ルールは以下の通り。

毎日24時までに継続日数x10,000以上のスコアを出す

毎日24時までにその日やったことのブログを投稿する

以上のどちらかに失敗したら終わり

1日目 19,117点 - ぜのぜ

昨日までで717,858点取れたのでそのためにやったことをまとめる。

リポジトリ: https://github.com/Gurrium/private-isu

追記）80万点達成した
25日目, 814,586 - ぜのぜ

追記）90万点達成した
26日目, 916,936 - ぜのぜ

追記）100万点達成した
28日目, 1,012,219 - ぜのぜ

環境

競技用インスタンス: c6i.large
ベンチマーカー用インスタンス: c6ixlarge

計測

MySQL

スロークエリのログ

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0

https://github.com/Gurrium/private-isu/blob/main/webapp/etc/my.cnf

nginx

アクセスログ

log_format json escape=json '{'
  '"time":"$time_iso8601",'
  '"method":"$request_method",'
  '"uri":"$request_uri",'
  '"status":"$status",'
  '"body_bytes":"$body_bytes_sent",'
  '"request_time":"$request_time",'
  '"response_time":"$upstream_response_time"'
'}';

server {
  access_log /var/log/nginx/access.log json;
}

https://github.com/Gurrium/private-isu/blob/main/webapp/etc/nginx/conf.d/default.conf

Go

pprof

import _ "net/http/pprof"

func main() {
    runtime.SetBlockProfileRate(1)
    runtime.SetMutexProfileFraction(1)
    go func() {
        log.Fatal(http.ListenAndServe(":6060", nil))
    }()
}

https://github.com/Gurrium/private-isu/blob/main/webapp/go/app.go

スクリプト

デプロイ

#!/bin/sh
# referenced from https://github.com/tatsuru/isucon13/blob/main/scripts/deploy

set -v

now=$(date +%Y%m%d-%H%M%S)
branch=${1-main}

update="cd /home/isucon/private-isu && git remote update && git checkout $branch && git pull"
restart="cd /home/isucon/private-isu/webapp/go && /home/isucon/.local/go/bin/go build -o app && sudo systemctl restart isu-go"
rotate_mysql="sudo mv -v /var/log/mysql/slow.log /var/log/mysql/slow.log.$now && mysqladmin -uisuconp -pisuconp flush-logs"
rotate_nginx="sudo mv -v /var/log/nginx/access.log /var/log/nginx/access.log.$now && sudo systemctl reload nginx"

git push origin $branch
ssh isucon@privateisup "$update && $restart && $rotate_mysql && $rotate_nginx"

https://github.com/Gurrium/private-isu/blob/main/webapp/scripts/remote/deploy

解析

#!/bin/sh

set -v

now=$(date +%Y%m%d-%H%M%S)

analyze_access="sudo alp json --file /var/log/nginx/access.log -r --sort=avg -m \"/image/[0-9]+.(jpg|png|gif), /@[a-zA-Z]+, /posts/[0-9]+\""
analyze_slow_query="sudo pt-query-digest /var/log/mysql/slow.log"

ssh isucon@privateisup "$analyze_access" | tee logs/nginx/digest.log.$now
ssh isucon@privateisup "$analyze_slow_query" | tee logs/mysql/digest.log.$now

rsync -v isucon@privateisup:/home/isucon/profile.pb.gz logs/pprof/profile.pb.gz.$now
go tool pprof -http=localhost:6060 logs/pprof/profile.pb.gz.$now

https://github.com/Gurrium/private-isu/blob/main/webapp/scripts/remote/analyze

ベンチマーク

本番ではポータルからだけどpprofの使い方のメモとして。

#!/bin/sh

set -v

pprof="/home/isucon/.local/go/bin/go tool pprof -proto -seconds 60 -output profile.pb.gz http://localhost:6060/debug/pprof/profile"
benchmark="/home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://privateisup"

ssh isucon@privateisup "$pprof" &
ssh isucon@privateisub "$benchmark"

https://github.com/Gurrium/private-isu/blob/main/webapp/scripts/remote/benchmark

改善

インデックス

スロークエリも見ずに必要そうなカラムに一通り貼った。

N+1の解消

初期状態*1では二重にN+1が起きていたり、コメントとユーザー両方でN+1が起きていたりするのでできるところから解きほぐした。現時点でも完全には解消できてないが、キャッシュと組み合わせたり、一旦全部引いてきてメモリ上で入れ替えたりして影響を抑えている。
https://github.com/Gurrium/private-isu/blob/ebe2728de17cea7b7286f1fc2cecccc6fd0b0e06/webapp/go/app.go#L195-L352

DBにあるデータのキャッシュ

セッション周りのユーザーのデータと投稿のデータなどをキャッシュした。エンコードに使うライブラリはencoding/jsonからsonnet*2に変えた。

今回はサーバーが1台だけなのでmemcachedはやめた。これだけでも結構早くなる。
https://github.com/Gurrium/private-isu/commit/b7d5b21f5526e734e3886e639011a3b8b6fec43e

追記）キャッシュ用のライブラリを使わずmapで管理する仕組みを自分で作って使うのが一番早かった。ライブラリはバイナリにしがちでencode, decodeが結構重い。

静的ファイルの配信

nginxから返すようにした。クライアントにキャッシュもさせた。
https://github.com/Gurrium/private-isu/pull/3/commits/0f67875f5fbfa72f442733ba80640c4c8bde7a98

外部コマンドからライブラリへの変更

ハッシュを計算するのに外部コマンドを使っていたのでライブラリに置き換えた。
https://github.com/Gurrium/private-isu/commit/2a397bb9736d6c67fecc397ba67aacfb02ad7f22

`fmt.Sprintf`の結果の使い回し

見出しからにじみ出るセコさNo.1。runtime.growsliceと一緒に潰したので正確な効果は分からないが、pprofで見ると結構時間がかかっていたのでそこそこ効いているのではないか。
https://github.com/Gurrium/private-isu/commit/4c3e9600211a74df59a601219e9c247d7bd592c1

`runtime.growslice`撲滅

必要なsliceの大きさがわかっているときは初期化時に確保した。
https://github.com/Gurrium/private-isu/commit/4c3e9600211a74df59a601219e9c247d7bd592c1

MySQLの設定の調整

書き込み
https://github.com/Gurrium/private-isu/pull/4/commits/6b6192f656a8dfb9edda76f7c42e689485059d01

interpolateParams=true
https://github.com/Gurrium/private-isu/commit/361772edde7d31e21b7a5ef5d80455176362684a

html/template脱出

テンプレートの処理に時間がかかっていたので手書きした。
https://github.com/Gurrium/private-isu/pull/4/commits/a55dad2a01f5ff7286c41f02402691fb00937a81

文字列の結合は遅いのでレスポンスを文字列で組み立てるのではなく直接http.ResponseWriterに書き込む。書き込む値も静的に決まるものは起動時にバイト列に変換しておいて使い回すとruntime.newobjectが減らせる。
https://github.com/Gurrium/private-isu/blob/ebe2728de17cea7b7286f1fc2cecccc6fd0b0e06/webapp/go/app.go#L667-L789

画像の配信元の変更

DBからファイルに変えた。DBからファイルへの書き出しを初期化処理に書くと時間がかかりすぎて多分失敗判定されるので、初めてリクエストが来たときにする。新規の画像は直接ファイルに保存する。教科書通り。

リクエストされるパスは/image/\d+だが、ファイルのパスは/public/img/\d+である。この場合はaliasを使えばよいと気づくのに結構時間がかかった。
https://github.com/Gurrium/private-isu/pull/3/commits/e20569e2e37ad698e37c91c9ff9f8b7049cc6b81

論理削除の処理の変更

0 or 1のフラグで0がほとんどなのでインデックスを貼っても大して効率がよくならなかった。メモリに論理削除されたユーザーのIDを持ってクエリに渡すようにした。
https://github.com/Gurrium/private-isu/commit/b9ea89a04be2822aa33ff6e5f328767120caa072

コメント数の保存

COUNT(*)は結構重い処理のようだったのでカラムに持つようにした。 https://github.com/Gurrium/private-isu/commit/d2c8d452179bafb243545c3f257f562854d06443

*1:https://github.com/catatsuy/private-isu/blob/b30df9d95ac2a81ba9cd3356458cf8650c45710d/webapp/golang/app.go#L174-L223

*2:https://pkg.go.dev/github.com/sugawarayuuta/sonnet

環境

計測