ISUCON 13に参加して12位 + 打ち上げ成功賞をいただきました

ISUCON

今年もいつものメンバー(pgmot, syusui)で「チーム7年目」という名前で参加して、12位 + 株式会社アークエッジ・スペース「打ち上げ成功賞」賞をいただきました！

衛星開発現場見学ツアーはメンバー全員が気になっていたのでとても嬉しいです。 せっかくなのでスコアが一気に上がった理由についても後ろの方に書いておこうと思います。

言語とツール

ISUCON 9ぐらいからずっとGo言語で参加しています。 自分は普段Go言語をほぼ書かないので、毎年ISUCONのときだけGo言語を書くみたいになってます。

分析ツールはkataribeとpt-query-digestを使っています。 alpが人気らしいですが、昔kataribeを使ってからそのまま使い続けています。 今年はパスにusernameが含まれていたので、以下のような置換用の設定を入れたりしてました。

[[replace]]
regexp = '/user/\w+(/|\s)'
replace = '/user/<account_name>$1'

kataribeとpt-query-digestを実行してDiscordに結果をアップロードするスクリプトを作ってあるので、ベンチの後にそれを実行するという運用をしています。

最近はいろいろとISUCON向けに便利なツールがあるみたいなので、いくつか試してみてもいいかもなと思ったりしてます。

自分がやったこと

主にアイコン周りとFillXxxResponse周りの改善を行いました。

kataribeを見るとアイコンのアクセスに時間がかかっていることに気がついたので、まずはここから取り掛かりました。 とりあえずDBに画像のhashを記録して、アイコンのエンドポイント以外では画像のバイナリを取り出さないようにしました。

If-None-Matchを見て304を返す部分は少し苦戦しました。 同じ値がヘッダーに来ているはずなのになぜか一致しないと思って悩んでましたが、ダブルクォーテーションで囲まれる仕様だったんですね…。 あと、ブラウザで挙動を確かめようとしても再現できなかったので少し戸惑ってました。

アイコンの画像については結局DBに入れたままにして、singleflightと1秒のインメモリキャッシュでごまかす形になりました。 実際のところnginxのログを見るとほとんど304を返していたので、ラッキーと思いながら放置してました。 304の割合が少なかったら追加で対応を考えていたかもしれません…。

アイコン周りの実際の変更はこんな感じです。

FillXxxResponse周りについては、メソッドを横断したN+1を愚直に直していくのは大変そうだったこととデータの更新がほぼなかったことから、IDに対応するデータの取得を行いつつsingleflightと60秒のインメモリキャッシュで対応しました。 どういうことかというと、func fetchLivestreamResponseWithCache(livestreamID int64) (*Livestream, error)やfunc fetchLivestreamResponseWithCache(livestreamID int64) (*Livestream, error)というメソッドを作り、この内部でIDに対応するデータのフェッチとfillの処理を行っています。 ただ、アイコンについては反映までの猶予が定められていたため、アイコンのhashの取得だけは1秒のインメモリキャッシュから別途取得して上書きする処理もしました。

kataribeで確認して遅かったエンドポイントや、他のFillXxxResponseから呼ばれている箇所などは置き換えていきましたが、一部はそのままの処理になってます。 N+1になっている部分も一部残したままになったので、全体的に置き換えておけばよかったかもと今更ながら思ってます。

singleflightとインメモリキャッシュの組み合わせは結構簡単にできて効果が大きいので、データの更新が少ない箇所では積極的に取り入れていきました。 結構コピペ実装な部分が多いので、ライブラリ化するか同等の機能を持ったライブラリを探したいところです…。

他のメンバーがやったこと

pgmot

initializeでDBのスキーマを適用するようにしてくれたのがとても助かりました。 他にはDBのインデックス周りを一通り対応してくれたり、統計情報の重いクエリを倒してくれました。

syusui

NGワード周りの改善とPowerDNSの分離をやってくれました。 元々pdnsutilでドメインを追加しているところをPowerDNSのREST APIを使った方法に変えていてすごかったです。

最終的な構成

  • isu1: PowerDNS + PowerDNS用のMySQL + go(PowerDNSのinitialize用)
  • isu2: nginx + go
  • isu3: MySQL(アプリ用)

DNS水責め攻撃でMySQLのCPU使用率がやばいのでPowerDNSを1台に隔離しよう、という話になってこの構成になりました。 isu1のDNSではisu2のIPアドレスを指定する形にして、HTTPリクエストはisu1に直接飛ばないようになってます。

スコアが一気に上がった理由

PowerDNSの分離自体には成功しましたが、何故かHTTPリクエストが全然来なくなってスコアが上がらないという現象に悩まされていました。 終了1時間前ぐらいからこの現象の解決方法を全員で模索していて、終了20分前ぐらいにSetMaxOpenConnsが少ないので増やしてみたところ、一気に60,788点まで上がりました。

ただ、この時点ではisu2にMySQLが同居した状態でisu3が使われていなかったため、残り10分ぐらいしかないところをsyusuiくんが冷静にisu3にMySQLを移行してくれました。 isu2からisu3にネットワーク越しにMySQLを接続できるように設定しているのがスムーズですごかったです。 自分はやることがないな…と思いながらslow query logを切ってないことを思い出したのでその対応をしてました。

そして終了2分前に最後のベンチマークをエンキューして、なんとか125,603点を出すことができました。

感想

PowerDNSの分離後にうまくスコアが伸びなかったり、こんなにも時間ギリギリまでやっていたりで今までで一番しんどかった気がします。 しかし、ギリギリまで粘ったことで12位に入ることができ、企業賞も頂けたのでとても嬉しかったです。

ランキングが隠れてから一番スコアが上がったチームに贈られる「伸びしろすごいで賞」がもらえるのでは…？と終了時に思っていましたが、もっと上のチームがいて(しかも1位のチームが更に点を伸ばしていて)かないませんでした…。

来年もISUCONがあれば参加したいです。そして上位に入賞できるように頑張りたいです。

Raspberry PiのSDカードからデータをサルベージする

Raspberry Piを起動するとカーネルパニックになってしまった。VirtualBox内のLinuxでSDカードをマウントしようとするとマウントがずっと終わらない。fsckを実行してもエラーが発生してうまくいかない…。

なんとかデータのサルベージはできたのでその備忘録。

使用した環境

手順

  • SDカードをMacに認識させる
  • diskutil list を実行してサルベージするIDENTIFIERを確認(今回の対象はdisk2s2)
host$ diskutil list

...

/dev/disk2 (external, physical):
   #:                       TYPE NAME                    SIZE       IDENTIFIER
   0:     FDisk_partition_scheme                        *64.5 GB    disk2
   1:             Windows_FAT_32 boot                    66.1 MB    disk2s1
   2:                      Linux                         64.4 GB    disk2s2

...
  • ディスクユーティリティなどでdisk2s2がマウントされていないことを確認
  • ddを実行して中身を書き出す
host$ mkdir -p ~/raspi
host$ sudo dd if=/dev/disk2s2 of=~/raspi/raspi.img
  • 所有者を自分自身に変えておく(Docker内でマウントするときに困るので)
host$ sudo chown abcang raspi.img
  • docker内でマウントする
host$ docker run --rm -it -v ~/raspi:/raspi --privileged debian bash
docker# mkdir /mnt/raspi
docker# mount -o loop /raspi/raspi.img /mnt/raspi
docker# ls /mnt/raspi

これで /mnt/raspi にマウントされるので、必要なファイルを退避すれば完了

参考

ISUCON11の予選を突破しました！

ISUCON

今年もここ数年と同じメンバー(@mot, @syusui)で「チーム五年目」という名前で参加して、ギリギリ24位で予選を突破できました！！ 本戦出場はISUCON 7以来なのでとてもうれしいです。

やったこと

言語はGoでやりました。(毎年ISUCONのときだけGoを書いている気がする。) 以下時系列順にざっくり起きたことを書いていきます。

  • mot: インフラ構築、kataribeとpt-query-digestを使えるようにする
  • mot: isu_conditionに(jia_isu_uuid, timestamp)の複合インデックスを作成
    • pt-query-digestで明らかにslowになってることに気がついたので対応
    • これだけで10000点を超えてびっくりした
  • syusui: ローカルで動かせるようにDB用のdocker-composeを用意
  • abcang: /api/trendでは最新のisu_conditionしか必要なかったのでLIMIT 1に変更
  • abcang: /api/trendのレスポンスを1秒ほどメモリにキャッシュ
    • 後に10秒に変えてみてもまだタイムアウトしたのでN+1を解決することに決めた
  • mot: ConditionLevelをカラムに持つように変更
    • Generated Columnsは使わず、愚直にinitialize時に変換したり、挿入時にConditionLevelも追加する形に
  • このあたりでDBの構成をどうしようかという話をして、最終的にisu_conditionのINSERTが重要になってくるだろうから水平分割にチャレンジするかということになりsyusuiが着手
  • abcang: /api/trendのisuの取得部分のN+1を修正
    • ついでにisuのimageを取得しないようにカラムをしぼったりもした
    • 今考えてみると、characterの順序について考慮してなくて挙動が変わってしまっていたがここはチェック対象外だったようだ…
  • mot: isu_conditionのPOSTをgoroutineで実行する形に変更
  • mot: dropProbabilityを変えてみて、一旦0.5に落ち着く
  • abcang: /api/trend用に最新のisu_conditionを1クエリで引けるようにする
    • 最新のisu_conditionを保持するテーブルを新しく作って、isu_condition追加時に更新するようにした
    • しかし、isu_conditionの追加時の処理がUPSERTではなくUPDATEになっていたため、新しいisuについて更新されない形になってしまった
    • 点数は上がったけどユーザーが増えなくなったぞ…？という話をしていた
  • mot: appとDBのインスタンスを分離してそれぞれ1台で動く形に変更
  • abcang: generateIsuGraphResponseがすべてのデータを取得していたので、特定の日付に絞って取得する形に変更
  • mot: 静的ファイルをnginxから返すように変更
  • abcang: UPSERTになってないことをsyusuiに指摘してもらって修正する
    • これによりユーザーは増えるようになったけど、スコアが全然出なくなってしまう
    • 仕方ないのでUPSERT処理をやめて、/api/trendは初期状態から変わらないようにした
  • syusui: 水平分割の準備ができたのでマージ
  • syusui: しかし整合性チェックに通らなくなってしまい、原因を探すも時間が迫ってきて結局諦めることに
    • なので最終的に構成はnginx+appが1台とDB1が台の合計2台
  • abcang: /api/trendは初期状態から変えないことにしたのでMax-Ageのレスポンスヘッダーを設定ようにした
    • よく考えたらメモリ側のキャッシュ時間も伸ばしておけばよかった
  • 最終的に最高スコアの108634点が出て、ここでコードフリーズすることに

f:id:abcang:20210823232423p:plain
スコアのグラフ

思いついたけど結局やらなかったこと

  • icon imageの改善
    • 画像はログインユーザーが登録したものしか表示されないのでそんなに問題にならないだろうと考えていて、計測してみて問題になったらやってみようという話で手をつけなかった
    • 今考えてみるとMax-Ageぐらいつけておけばよかったかもしれない(同じユーザーが何度もアイコンを取得していたかどうかは不明だけど)
    • isuのクエリ時にimageを除外する案もあったけど、結局あまり手を出せなかった
  • created_atとupdated_atの削除
    • DEFAULT CURRENT_TIMESTAMPになっているけど、一切使われてないので消すだけで若干INSERTが早くなるかも…？と思ったけど結局やらなかった
  • 不要そうなトランザクションの削除
    • SELECTしかしてないところでトランザクションがあったりと無駄な感じはあったけど、ボトルネックではないから後でいいか…と思っていたら結局直さないままになってしまった
  • /api/isuのN+1の修正
    • 1人のユーザーが登録するisuの数はたかだか知れているだろうから直さなくていいかと判断

感想

今回はしっかり計測しつつ遅いところから順番に修正できていたと思うのでよかったです。 ただ、/api/trendは最初の状態から一切替わらずユーザーが全く増えないという事になってしまったのは少し悔しかったです。 あと、得点計算についてはややこしくて理解を諦めてしまっていたので、これについては少しまずかったかな…と若干反省です。

予選を突破できたのはチームメンバーの力があってこそなので本当に感謝です。 過去に参加した本戦ではあまりスコアを伸ばせなかったので、今度こそは本戦でいいスコアが出せるように頑張りたいです。

最後に、運営の皆様ありがとうございました。本戦でどんな問題が出題されるのか楽しみです。

ISUCON 9予選の反省

日記 イベント ISUCON

ISUCON 9の予選に敗退しました。 前回のISUCON 8では同じように予選敗退して記事は書かなかったが、今回はよくない動きをしてしまったので戒めとして反省記事を書くことにした。(感想も書きます)

本番前

ISUCON今年はどうしようとTwitterでつぶやいたところ、ISUCON 6や7のときのチームメンバー(mot, syusui)が声を上げてくれたので、チーム3年目として参加することになった。

今まではrubyで参加していたけど、goで参加してみないか？とmotさんから提案があったのでgoで行くことになった。 goは一切書いたことなかったので、A Tour of Goを一通り読んでISUCON 8の過去問を触って、という感じで1週間の夏休みを使って勉強した。 これでISUCONをやるには問題ないぐらいにはgoが書けるようになったと思う。

本番やったこと

  • pprofを使えるようにした
  • 新着アイテム、カテゴリ別新着アイテムの並び順をredisから取れるようにした

以上という感じで、全然取り組めなかった。 pprofとかで遅そうな場所を把握した時間が12時ごろ、新着アイテムの並び順をredisから取れるようになったのが15時半ごろ、カテゴリ別新着アイテムは17時ごろに実装完了した。他に何もできなかった。

カテゴリ別の新着アイテムの取得の部分が遅いと気づてコードを見たときに、N+1クエリがあったのと一覧取得クエリに複数のIN句とOR条件があったのに気づいた。 一覧取得クエリはindexを張ったりIN句やOR句をなるべく使わないように修正する手もあるなと思ったけど、redisのsorted setを使えば一気に解決できていいのでは？と考えてそうすることにした。 この判断が本当によくなかったので大反省をしている。

やったことに対する反省点

  • 実装に時間がかかりすぎてしまった
    • 1, 2時間でできるだろうと思っていたけど、その2倍以上はかかってしまった
    • 練習時には無限に時間がある中でredisを使った実装も試してたので、サクッと行けるだろうと過信してしまっていた
    • そのため自分は他の部分に着手できなかった
    • ときには大規模な改修も必要かもしれないが、競技時間が短かったり改善するとボトルネックが別の場所に移りやすかったりなどの理由から、基本的には短時間で試せる改修を積み重ねて行くほうがいいなと思った
  • 時間がかかった割に効果が薄かった(と思う)
    • どれくらい改善したのかちゃんと計測してないのであれだが、ボトルネックではなかっただろうからおそらくindexを張るだけでも十分だった気がしている
    • 解決すべきボトルネックなのかもわからない状態で大規模な改修を試みるのはよくないと反省
    • index張るのは一瞬でできるわけだからそれを試してみてからでも全然遅くなかったと思う

その他の反省点

  • APIのアクセス傾向やレスポンスタイムをあまり把握してなかった
    • nginxのアクセスログもgo側のWebフレームワークで出力したアクセスログもほとんど見てなかった
    • 外部APIを叩く実装があったりDBのロックを取る箇所があったりとpprofだけではわからない部分が多かったので明らかに見るべきだった
    • アクセスログを見て、遅いエンドポイントから詳しくボトルネックになっている部分を掘り下げていくのがよさそうだなと思った
    • 自分自身はkataribeやalpを触ったことないので次回(あるのなら)までには勉強しておこうと思った
  • 結局DBのindexは全く追加してなかった
    • slow queryは出していて最初ちらっと見ただけで何もしてなかった…
  • 購入周りはロックで詰まったりするだろうなと薄々考えていたけど何もできなかった

その他感想

  • キャンペーン機能でアクセス数をこっち側で制御できるのはおもしろいなと思った
    • 講評の記事を見ると初出ではなかったらしいので過去問対策不足だったかも
    • キャンペーン機能の数値を変えるとログインの負荷が一気に上がることに気がついたのが後半だったので、今後同じような仕組みがあったら早めにいろんな値で試してみたほうがいいなと思った
  • Go Modulesよかった
    • go初心者でも依存モジュールのインストールに全然躓かなかった
  • bcryptの負荷が高かったのが驚いた
    • ログインでこんなに詰まるものなんだと驚いた
    • ログイン専用のサーバに分けて他の処理に影響が出ないようにすることは学びになった(競技中には対応できなかったが)
    • ISUCON 8の本戦で同じような問題が出ていたことを知って、これも過去問対策不足だったなと思った
    • ベンチを回せば回すほどパスワードのハッシュを更新できるのはどうなんだろう…と思ってしまった
  • 椅子が売れた数がポイントになって、椅子が売れるようにある程度調整してもいいというルールは実際のサービスっぽくて面白いなと思った
    • その反面、スピードアップコンテストとはちょっと違ってきている気も…という風にも少し思った(文句はないです)
  • 機能が盛りだくさんで難しかったけど面白かった
    • 商品の出品から決済、発送まで一通り機能があるのがすごいなと思った
    • 決済や発送周りはちゃんと外部APIとして用意されていて気合を感じた
  • 次回があれば今度こそ本戦行きたい…