時間はすげえ適当、本当に適当
@akenshoさんと@li_sakuさんとチームluminousで出た。
このメンバーで出るのは一昨年に続き二回目。
最終スコアは11.7kくらい通過できたらいいな〜。
使用した言語
Go
解析ツールの準備
@akenshoさんが全てやった。
- alp: 遅い/頻繁なhttpリクエストを把握するため
- myprofiler: 頻繁なMySQLクエリを把握するため
- pprof: GOアプリのボトルネックを把握するため
- mysqlのslowquery報告機能: 遅いクエリを把握するため
本番前
一ヶ月前
そろそろ練習しないとな〜と思ってISUCONをやっては忘れるGoに触る
一週間前
isukariの練習しなきゃとかいうツイートをした(ニアピン賞)
https://twitter.com/kyuridenamida/status/1168077007088803841
本当にisucariで笑ってしまったが、さすがにこれは容易に予想が出来たのでセーフ。
本番
開始前
09:30にAtCoder社に行って準備をする(早起き!)
10分遅延してくれてなんとか朝ごはん食べる暇ができた。ありがとう。
00:00 開始
とりあえずルールを把握したり、gitリポジトリを作ったり、色々。
isuconというローカルユーザーを作ってもらっていたのを無視してrootでgitを操作していたらチームメンバーがgitをisuconユーザーから操作できなくなっていたらしく、罵倒される。
01:00 - 様々なツールの整備が完了
何もしていないGOの参考実装に対するベンチを走らせる。2210点くらい。
pprofとかも走らせる。
pprofがpdfとかで表示されてCool! ありがとうsakuさん
01:30 最初の気づき bcryptは遅い
pprofの結果bcryptが遅すぎることに気づく。暗号化ハッシュ化-、やめるか!w(←この時点ではこれが違反になるというルールを把握していない)
「初期ユーザーの数は3!wハッシュ強度の変更は容易!w」みたいな議論をするが明らかにMySQLのテーブルを見ると嘘であることが分かる。4000コある。だめ。
初期のデータベースにはハッシュしかないのでそれから平文を復元することは不可能だが、以下のようなマイグレーションプランを考える。
- 初期4000ユーザーに対するリクエストで来るパスワードを盗聴して、ログインに成功したらそれを別のテーブルpassword_listに保存する。
- 平文パスワードがpassword_listテーブルに存在したらそれを使って、そうでなかったらbcryptで今まで通り比較。
- 新しく追加されるユーザーについては無視する。
- password_listは消さない
これでベンチを走らせるたびにbcryptの負荷が下がる最高の機構が完成。僕は高速化のためにこんなことしてるWebサービスが実在したら心底軽蔑するし絶対に使いたくないんだけど「これはISUCON、OK」という気持ちを強く持った。
とりあえず平文保存実装を僕がやって、akenshoさんがansibleによる様々なもの(Goコンパイラとか)の整備にとりかかる。
ところで作業中にinitial.sqlをpushしようとして無理やりgit addした結果、initial.sqlが神隠しにあい、また罵倒される。どうして...
03:00 平文保存のコードが一応完成
ベンチ走らせたらバグる。チームメイトに罵られる。Ω＼ζ°)ﾁｰﾝ
sqlxわからん。データバインディングに失敗しているようにも見えるが、なぜ...?
03:30 バグが取れる
バグの原因わかんね〜って一生悩んでたら本当にあった怖い話としてGOは先頭が大文字か小文字でvisibilityが変わるという話をakenshoさんに教えてもらう。
type PasswordList struct {
ID int64 `db:"id"`
userID int64 `db:"user_id"`
plainPassword string `db:"plain_password"`
↓
type PasswordListItem struct {
ID int64 `db:"id"`
UserID int64 `db:"user_id"`
PlainPassword string `db:"plain_password"`
}
おわかりいただけただろうか。
この違いがsqlxのバインディングに影響していて、頭を捻っていた。
僕はこれに関して「Go言語さんサイドの仕様決定プロセスに問題がある」という脳内で責任転嫁済みだったのだが、現実ではチームメイトに罵られれる。
いやGoやってなくてすみません。多分一生自力では気づけなかった気がする。
03:30 ベンチ走らせまくり
平文パスワードを集めるためにひたすらベンチを走らせる。MySQLコネクションがさっきの変更によりリークしてたりして冷える。ごめん。直すから許して。
指定した負荷度が低かったため50コくらいずつしか増えない。
先が遠いけど終了までには4000コ溜まってるだろうという気持ちになる。
途中で負荷を上げたらよいことにチームメイトが気づき負荷を0→2に上げる。一回にいっぱい集まって最高。
もっかいpprofを走らせる
04:00 第2の気づき: getNewCategoryListが遅い
bcryptくんの存在感が薄くなってるなあ。次は「getNewCategoryList、遅いぞ!w」とpprofに罵られる。
コードを読むと重そうなクエリ + N+1問題が起きている。
明らかに怪しそうなN+1問題からやっつけようという気持ちになる。N+1問題は二つの関数によって引き起こされていた。
- getCategoryByID
- getSimpleUserByID
とりあえず完全にメモリにのっけてよさそうなcategory周りからキャッシュしていく。
04:00 第3の気づき: MySQLのチューニングが効きそう
コネクションリークの対処とか考えてるときにチームメイトが気づいた気がする。
akenshoさんが色々設定する。
チームメンバーが何か良いことをする度にありがとうございますって連呼してたら「お前の目標は感謝なのか?」と罵られる。
04:20 大量に平文パスワードをかきあつめおわる + MySQLのチューニングをしたりする
チームメイトがめっちゃMySQLのメモリとかを弄っている。いい感じ。
7000点くらい、スコアがよくなる。やったぜ。3位。
04:30 getCategoryByIDをバグらせる
またバグらせてベンチ死んでチームメイトに罵られる。ごめん許して。
他にも、PRがあったほうがCR出来て便利だろ!って罵られる。許して。
とりあえずケツを叩かれながらさっさと直して動くようにした。
04:35 getCategoryByIDが直る
これだけだとN+1問題の完全解消にならないのでベンチにはさほど影響がなかったはず。
04:40 getSimpleUserByIDのオンメモリ化に取り組む
getSimpleUserは基本的にはオンメモリにできて、唯一出品数だけはリアルタイムに変わりそう。これも頑張ってオンメモリにする。
concurrent mapを使ったことがなかったがとりあえず
https://github.com/orcaman/concurrent-map
これを使わせてもらった。初めて使うのでドキドキした。
よく考えるとincrementはアトミックにやらないということに実装してるときに気づき、地獄に落ちなかった自分に感動。
https://github.com/uber-go/atomic
を導入する。どっちも使ったことがないライブラリでドキドキワクワク。例に漏れずGoわからなさすぎて苦労する。
05:00 第4の気づき: getNewCategoryList内のクエリは非効率的
僕がアプリを弄っている間にsakuさんとakenshoさんが発見してくれた。
saku「explainしたらサイアクな感じ。とりあえず思考停止でindex貼っていい?」
まあやってみて早くなればOKなのでとりあえず思考停止indexを貼って頂く。
05:00 第5の気づき: 平文保存はルール違反
_sakuが気づいた。マニュアルにも書いていたし、運営からも「平文保存はやめろ」とだけお達しが来る。わかるな〜〜〜〜
そもそも暗号化ハッシュ化関数が満たすべき性質についての言及が一切無いので、困ってしまった。
とりあえずこのままだと失格になってしまうし、暗号化しないといけないのだが、適当に性質を仮定して出戻りが起きたらサイアクなので、慎重にやることにした。
sakuにサポートチャットで「@運営 『パスワードを平文で保存する』という意味は、ユーザが入力したパスワードをそっくりそのまま保存する、という意味と同値ですか？」と聞いてもらう。
しかし長らく返事がない、他の参加者の別の質問には反応している、困ったなあ...
06:00 インデックスを貼ったりしおわる
改善する。負荷も4にしてみる。
たしかスコアが上がった? 9000点くらいになった?
06:00 再度平文保存に関する質問をする。
ここまで返事がないと見逃しているのかと思い、もう一度sakuさんに質問してもらう。
saku「@運営 『パスワードを平文で保存する』という意味は、ユーザが入力したパスワードをそっくりそのまま保存する、という意味と同値ですか？」
再度返事がない。理由はわからないが返事の保留は意図的なものだと判断して諦めることに。
06:20 getSimpleUserByIDのオンメモリ化が完了
全員でデバッグしてちゃんと動いて、感動... 11500点くらいが出る。
06:30 独自暗号化関数の実装
質問の答えが相変わらず返ってこないので、そろそろ平文で保存しているものを暗号として保存することにする。（追記:本来やるべきはハッシュ化でしたが平文じゃなくなればいいので暗号化でも良いことにする）
ISUCONに適した独自の暗号化関数を実装することにした。
どういうものかというと
def create_encrypted_pasword(original_password string) string {
return original_password + "#";
}
これを用いたログインは平文比較とほぼ同等の速度でありかつ強度も用途に適しているという判断になった。
func insertPlainPassword(userID int64, password string) error {
_, err := dbx.Exec(
"INSERT INTO `password_list` (`user_id`, `plain_password`) VALUES (?, ?)",
userID,
password + "#", // 暗号化
)
return err
plainPass, err := getPlainPassword(u.ID) //実ははプレインではありません。
if plainPass != password + "#" { // 復号化
err = bcrypt.ErrMismatchedHashAndPassword
} else {
err = nil
}
誤解を産む命名を含むロジックではあるが、コメントにもあるように、明らかにプレインではない。
このあと、平文は破棄して、新暗号でデータベースに保存することにする。DBのクエリを叩くのが怖かったので完全に収集し直す戦略。
収集しはじめの頃点数が2000点台まで落ちてびっくりした。bcryptやっぱりボトルネックだったんだね。
07:00 凍結・再起動試験等に着手しはじめる
大体4000コの新暗号による暗号化済みパスワードの収集が終わる。点数が元に戻ってくる。
ISUCON最後のほうは色々試したりして事故ったら元も子もないので、危ない橋を渡らないようにしようという雰囲気が漂う。
とりあえず再起動試験をやろうという話になる。個人的にオンメモリの出品数カウントとかめちゃくちゃこわいし大賛成だった。
再起動試験をするとmysqlが先に起動していないという理由でisucari.golang.serviceが死んでいることが分かる。
これは出品カウント以前の問題だったし再起動試験して良かった〜。
07:30 再起動試験に成功
再起動試験に成功し、出品カウントもうまくいってる。やった〜
07:50 最後のベンチ走行
再起動した直後のフレッシュな状態でベンチマークを走らせる。最高得点11700くらいが出る。
やった〜もうおしまいおしまい。放置。最終的にインスタンス数は1でした。
片付け。
08:00 終了
楽しかった〜!!スコアリング方式のおかげか超ベンチが安定していたし、快適だった。運営に感謝
終了。AtCoder社のホワイトボードにsnukeのイラストを描いて去る。
あとは祈るだけ。これでパスワードの平文保存に関して質問はしたし(しかも二回も!)、厳密な定義が存在してそれによって失格になったら普通に悲しいけど運営のフェア精神を全面的に信頼しているため頼む頼む
結果発表 通過してました!
ISUCON9 2日目結果と本選出場者決定のお知らせ : ISUCON公式Blog
通過してました!本戦がんばります!
余談: しょぼい暗号化（とかハッシュ化）を使うことの是非に対する本音
運営がbcryptに改善の余地を設けたのが意図的なのかについて考えていたんですが、この記事を読む限りISUCON8の本戦ではbcryptの使用を明記されていたように見えます。
http://isucon.net/archives/52598691.html
パスワードのbcrypt
パスワードをbcryptでハッシュ化していましたが、これがアプリケーションがCPUをつかうほぼ唯一の箇所でした。
また「パスワードはbcryptでハッシュ化しなければならない」と仕様に明記されていたため対策できないような錯覚をさせていましたが、コスト(ストレッチング回数)に関しては何も言及していないためコストを最小値にすると大幅にCPUが改善するものでした。
今回そのような指定はありませんでした。考えられる可能性は
- 単純に今回も同じことを仕様に書く予定だったが書き忘れた
- 意図的にbcryptを他の方法に置き換えることを想定した
どちらにしろ 1.に関しては早い段階で訂正のチャンスがあったのにしなかったということは2.の線が濃厚で、それを強く信じています。
返事が無かったことに関する理由は謎です。
