ISUCON7に id:kazeburo さんと id:gfx さんと、チーム「スギャブロエックス」で出場して、入賞もならず、最終結果5位で終わりました。
うーん 悔しい。
お題
WebSocketで通信しつつ各ルームで複数のユーザが操作するので同期をとりながら値を更新していく、的なもの。
チームの動き
予選のときと同様に、言語はNode.jsを選択。 今回はTypeScriptを使うようにしていっても良いのでは、と gfxの発案で序盤にすべてのコードをTypeScriptに変換して それを中心に進めていくことに。
実際、TSLintが良く効いて構文エラーや簡単な型の不一致などはすぐに気付くことができて編集しやすくて良かったです。
序盤の各サーバへのログインやNodeのバージョン変更、deployのためのscriptなどの環境整備はお2人に任せて、自分はとにかくアプリケーションをまずgitリポジトリに入れて ローカル環境で動かせることの確認、コードの確認など。
MySQLのトランザクションを使っている部分などは正直あまり詳しく分からなかったので そこらへんの解消はkazeburoさんにお任せして、とりあえずは 参照だけで更新のない数レコードだけのm_itemテーブルを使わないよう定数化して排除する、くらいのところから始める。
トランザクションによる負荷を少しでも軽減させるために、と各サーバでMySQLも立ち上げて 同じroomへのリクエストは単一のサーバにリクエストが集まるように4台それぞれ分けて動かすように kazeburoさんによる変更も。
1000回ループ問題
昼御飯の時間あたりから CPUの高負荷をとにかく取り除きたいな…と思いながらコード見ていて calcStatus関数の中で1000回のforループを繰り返しているのに気付いて、そこを消そう…！と思い至って そこを完全に任せてもらい改善の作業をすることに。
元のコードはこんな感じ。
calcStatus (currentTime, mItems, addings, buyings) { ... // currentTime から 1000 ミリ秒先までシミュレーションする for (let t = currentTime + 1; t <= currentTime + 1000; t++) { totalMilliIsu = totalMilliIsu.add(totalPower) let updated = false // 時刻 t で発生する adding を計算する if (addingAt[t]) { let a = addingAt[t] updated = true totalMilliIsu = totalMilliIsu.add(bigint(a.isu).mul(bigint('1000'))) } // 時刻 t で発生する buying を計算する if (buyingAt[t]) { updated = true const updatedID = {} for (let b of buyingAt[t]) { const m = mItems[b.item_id] updatedID[b.item_id] = true itemBuilt[b.item_id] = itemBuilt[b.item_id] ? itemBuilt[b.item_id] + 1 : 1 const power = m.getPower(b.ordinal) itemPower[b.item_id] = itemPower[b.item_id].add(power) totalPower = totalPower.add(power) } for (let id in updatedID) { itemBuilding[id].push({ time: t, count_built: itemBuilt[id], power: this.big2exp(itemPower[id]), }) } } if (updated) { schedule.push({ time: t, milli_isu: this.big2exp(totalMilliIsu), total_power: this.big2exp(totalPower), }) } // 時刻 t で購入可能になったアイテムを記録する for (let itemId in mItems) { if (typeof itemOnSale[itemId] !== 'undefined') { continue; } if (0 <= totalMilliIsu.cmp(itemPrice[itemId].mul(bigint('1000')))) { itemOnSale[itemId] = t } } } ... }
currentTimeより以後のaddingAt, buyingAtの情報を元に、1000ms後の状態をシミュレーションする、というもの。
addingAtもbuyingAtも無ければ、少なくとも totalMilliIsuの値の計算はtotalPowerの値を足すのを繰り返すだけなのだから 掛け算に変換すればいいだけ。
ただ それによって途中でアイテムが購入可能になったらその時刻は記録しておかないといけない、というのがあるので それだけは逆算して割り算で求める。
まずは 「addingAtもbuyingAtも無ければ」という条件に限定して上記の変更をしてみたが、(実際どうだったか確かめていないけど)殆ど効果なかったようで、やはりaddingAt, buyingAtがあるときも処理していかなくては、と大幅に変更をしていく。
基本的な考え方は 「addingAtがあった時刻」or「buyingAtがあった時刻」だけ必要な更新をして、その間の区間はtotalPowerが加算されるだけだから掛け算で加えていく、という形。
最終的なコードは以下のようになった。
calcStatus(currentTime, mItems, addings, buyings) { ... const eventTimes = new Set<number>(); // adding or buying times for (let a of addings) { if (a.time <= currentTime) { ... } else { ... eventTimes.add(a.time); } } for (let b of buyings) { ... if (b.time <= currentTime) { ... } else { ... eventTimes.add(b.time); } } // イベントが起きる時間だけ時系列に列挙する eventTimes.add(currentTime + 1000) let prevTime: number = currentTime Array.from(eventTimes).sort((a, b) => a - b).forEach((time) => { // 1000以上は計算する必要なし if (time > currentTime + 1000) { return } // 直前の状態は保持しておく const prevToatalMilliIsu = totalMilliIsu totalMilliIsu = totalMilliIsu.add(totalPower.mul(Number(time) - prevTime)) if (addingAt[time]) { let a = addingAt[time] totalMilliIsu = totalMilliIsu.add(a.isu + "000") } // 購入可能になっていたらその時刻を逆算 for (let itemId in mItems) { if (typeof itemOnSale[itemId] !== 'undefined') { continue; } if (0 <= totalMilliIsu.cmp(itemPriceX1000[itemId])) { if (totalPower.cmp(BI0) == 0) { itemOnSale[itemId] = time } else { const diff = itemPriceX1000[itemId].sub(prevToatalMilliIsu) const div = diff.div(totalPower) const mod = diff.mod(totalPower) const t = mod.eq(BI0) ? div.toNumber() : div.add(1).toNumber() if (prevTime + t < time) { itemOnSale[itemId] = prevTime + t } else { itemOnSale[itemId] = time } } } } if (buyingAt[time]) { const updatedID = {} for (let b of buyingAt[time]) { const m = mItems[b.item_id] updatedID[b.item_id] = true itemBuilt[b.item_id] = itemBuilt[b.item_id] ? itemBuilt[b.item_id] + 1 : 1 const power = m.getPower(b.ordinal) itemPower[b.item_id] = itemPower[b.item_id].add(power) totalPower = totalPower.add(power) } for (let id in updatedID) { itemBuilding[id].push({ time: time, count_built: itemBuilt[id], power: this.big2exp(itemPower[id]), }) } } if (time != currentTime + 1000) { schedule.push({ time: time, milli_isu: this.big2exp(totalMilliIsu), total_power: this.big2exp(totalPower), }) } prevTime = Number(time) }); ... }
currentTimeからその1000ms後までの区間で、addingAtとbuyingAtがあった時刻を時系列に並べ、その区間ごとに前のイベント時刻との差分を使って掛け算でtotalMilliIsuに加える値を計算。
なんとなく実装して 用意されていたユニットテスト(めっちゃ有り難かった)も通った、のが14:40。 これでどうだ！と走らせてみると
負荷走行前のバリデーションに失敗しました。time = 1511588407211 の status において on_sale[item_id = 5].time が正しくありません : actual 1511588407999, expected 1511588408000
!!! 1msずれてる !!!
どっかで境界値バグがあったか… と試しにitemOnSaleのtimeの値を+1してみたりしたけどやっぱり通らず(当たり前か。この時間は無駄だったな…)、思った以上にバリデーションが細かくチェックしていた。
うーん うーん と唸りながらコードを見直して totalMilliIsuの更新タイミングと購入可能チェックのタイミングが順番がおかしかった…と思って 直したり
負荷走行中のバリデーションに失敗しました。room ROOMmVe0gsm8OU7zKMKUGNOQ にて schedule に同一の時刻が含まれています
と出て そうかaddingAtとbuyingAtは同時刻に起こることもあるから単純に混ぜるんじゃなくてuniqueにしなきゃダメじゃん、ってなったり
あとはon_saleの時刻がどうしても大きくズレることがあって まとめて加算後に購入可能になったときitemPrice - prevToatalMilliIsuをtotalPowerで割ってprevTimeに足すだけだと思ってたけど 実はtotalPowerの値は小さくてaddingAtで大きく加算されたことによって購入可能になった場合もあるな、ということに気付いて直し。
さらに割り算も単純に割ってたらダメで小数は切り上げないといけない。これが境界値バグだった、のに気付いたのは一番最後だった。しかしbigintではMath.ceilは出来ないのか… divとmodで分けて計算して、modが0より大きかったらdiv+1に…と修正。
とにかくことごとく勝手に罠にハマりまくって、ようやくちゃんと通ったのが 16:15頃。結局3時間くらいここにかかってしまった…。 とりあえずスコアは20,000点を越えるようにはなったけど、そこまですごいブレイクスルーにはならなかった。。
終盤
あとは無駄な部分を少しずつ潰しておこう、と itemのgetPrice(count)やgetPrice(count)はcountの値が同じなら同じ値を返すだけだしキャッシュしていこう、と一度計算したものは記憶させてそれを返すように、など。
あとで気付いたけどこういうのはinitialize時にある程度の数まで計算してしまえば走行中に計算するのは1回も無くなるんだった。
結局あまり時間も残っておらず そこから大幅な改善も出来ず、あとは2人の作業を見守るだけ、みたいな感じになってしまった。
再起動テストや微調整などを見守り、最高スコアは18:03に29,944を記録していたけど、それ以上の数字は出ないまま フィニッシュ。
反省
インフラよりアプリケーション寄りの問題だったので、主にアプリケーション担当として参加させてもらっている以上はもっとバリューを出していかなければダメだった。
もっと素早く正確にコードの変更をガンガン進めていければ インメモリ化してMySQLから離れる施策も検討できたかもしれないし、他にもチューニングしていける箇所は改善していけたはず。
1000回ループ問題も そこまで効果をちゃんと考えずに取り組んで すごい時間かかってしまったし…。 (このへん 競プロ勢のヒトとかだったらもっと簡単にサクっと解決できていたんだろうなー とか)
そもそもbigintの演算がどれくらい負荷になっていて どこを最優先で減らしていくべきかをちゃんと分析できていなかった、というのもある。
もっと各所でどんな値が流れていてどんな処理が時間とCPUを食っているか、を意識して調査しながら解決していく姿勢・技術が必要だった。
などなど、アプリケーションエンジニアとしての力不足を痛感する敗戦でした。 この先もまだこういう道で生き残っていきたいし、ちゃんと勉強して精進していかねばなー… と思ったのでした。
まとめ
- やれるだけのことはやった
- けど力不足でした
懇親会では色んな方と反省会しながらお話できて良かったです。ISUCONケーキめっちゃ美味しかった。
運営・出題の皆様、主催・協賛の皆様、そして一緒にチームを組んで戦ってくださった id:kazeburoさん、id:gfx氏、本当にありがとうございました！
