inSmartBank

AI家計簿アプリ「ワンバンク」を開発・運営する株式会社スマートバンクの Tech Blog です。より幅広いテーマはnoteで発信中です https://note.com/smartbankinc

ISUCONが業務に役立つ瞬間 - 決済処理時間の悪化を解決するまでの軌跡

Engineering

こんにちは。株式会社スマートバンクでサーバーサイドエンジニアをやっております、@moznionです。

Webアプリケーションのパフォーマンスに問題が起きている時、みなさんはどのようにアプローチしていますか？　私はISUCONで培ったテクニックを使うことが多いように思います。

今回はそのような「ISUCONで学んだ知見」が役に立ったパフォーマンスチューニング事例があったのでそのご紹介をできればと思います。

背景と課題

株式会社スマートバンクではカード *1 決済をサービスとして提供しており、この決済が快適に行なえているかどうかはサービスの品質を捉える上で重要な指標となります。

そこで我々はこの決済処理にかかる処理時間を「決済レイテンシー」と定義して1.5秒のSLI *2 を設定し、エラーバジェットを設定して継続的な監視を行なっています。

SLI/SLOの設計・運用の詳細につきましては同僚の@maaaatoによる弊ブログ記事を併せてご覧ください: 「我々はこうしてSLI/SLOを設計して運用を始めました -これからSLI/SLOの運用を始める人に向けて-」というタイトルで登壇してきました - inSmartBank

そしてある日、このエラーバジェットが大きく減少していることに気付き *3 これは何かがおかしいのでは、ということで調査が開始されました。

数値を見ることによる「性能が劣化しているのでは」という気付き

問題発見までのプロセス

株式会社スマートバンクではNew Relicを用いてシステムメトリクスを収集しているため、それを用いて調査することとなります。

そういえば2020年に開催されたISUCON 10ではNew Relic株式会社様のスポンサーによりNew Relicが会期中無料で使えるというありがたい出来事がありましたね

このように、普段からメトリクスを収集しておくことは大変重要であることがわかります。

実際のNew RelicのTop 20 database operationsの様子。Slow SQLではオンラインで2秒近くかかっているクエリを見ることもでき、大変興奮します。

さて、決済の処理の中で呼び出されるMySQLクエリについてあたりを付けて調査してみました。New Relicの Top 20 database operations を見てみると時間ウインドウ内の累積で時間がかかっているクエリをランキング形式で見ることができます。直感的にはランキングの最上位から順に解決していけば良いように思いますが、しかし「単純にクエリ件数が多いもの」 *4 が上位に出てくることがあるため、このあたりには注意が必要です。このあたりもISUCONのゲーム性と似たものがありますね。実際のアプリケーション特性を鑑みることが肝要です。

レイテンシーのパフォーマンス改善、とりわけ「SLIを満足できないリクエストのためにエラーバジェットが低下している」という状況下では、「特定の1リクエストあたりに時間がかかるクエリがあり、それに足を引っぱられている」という状況を仮説として立てました。すべての処理 (クエリ) が等しく遅いのであればエラーバジェットは即座に消化されてしまいますが、徐々に減っていくあるいは増減を反復するようなパターンであれば何らか特定の条件においてスループットが劣化していると考えられるためです。

そこでエラーバジェットが低下しているタイミング周辺のスロークエリを中心に調査したところ、

  • BalanceTransaction sum
  • PresentmentAuthorizationRequestHistory exists?
  • Card find

の3つが浮かびあがってきました。

これらは処理時間として500msから2000ms前後を推移しており、エラーバジェットに対し強く影響していることが予想できました。2000msもかかるクエリが実行されてはそのクエリだけでSLIを違反してしまいますものね。

ルーク、サマリーテーブルを使え

前者2つの

  • BalanceTransaction sum
  • PresentmentAuthorizationRequestHistory exists?

のクエリはそれぞれ重めの集計やサブクエリが実行されるものでした。

これら個別のクエリについて注目し、問題の解決を図ってみましょう。

BalanceTransaction sum

このクエリは以下のようなものでした。

-- 或るカードの決済支出の総額を計算するクエリ。
-- いっぱいJOINして、「残高取引」と「決済」を紐付ける。
SELECT SUM(`取引残高`.`amount`)
FROM `取引残高`
INNER JOIN `決済リクエスト履歴との中間テーブル` ON ...
INNER JOIN `決済リクエスト履歴` ON ...
INNER JOIN `決済` ON ...
WHERE
  `決済`.`card_id` = ?

このクエリは「或るカードの決済支出の総額」を計算している素朴なSUMのクエリです。決済にあたってそのカードが今までに決済した総額をチェックする必要があるため、オンライン処理の中でこの集計クエリが呼ばれるわけですが……これは大変ですね。

というのもカードが持つ決済すべてを集計してSUMを取るわけなので、カードの決済件数が増えれば増えるほど読み取らなければならないレコードも増えることは自明です。なのでたくさん利用しているユーザーであればあるほど体験が悪くなるという歓迎できない状況となっていました。

なのでこの問題に対応するためにあらたに「カードの状態・アクティビティ」を保持するサマリーテーブルを作成し、その中に「決済総額」columnを用意し、決済のたびにそのcolumn (過去の決済総額) に対して決済金額を加えてUPDATEすることによりSUMを発行することなく総決済金額を取り扱えるようにしました *5。

これにより、決済のたびに重量のあるSUMクエリを発行する必要が無くなったため必然的にパフォーマンスが向上することとなりました。

PresentmentAuthorizationRequestHistory exists?

これは以下のようなクエリであり、

-- 初回決済かどうかをサブクエリのヒット数に応じて判断する。
-- カウントの結果が1であれば初回決済。
SELECT COUNT(*)
FROM (
  -- いっぱいJOINして条件に合う決済履歴を引っぱってくる。
  SELECT ? AS one
  FROM `決済リクエスト履歴`
  INNER JOIN `決済` ON ...
  INNER JOIN `カード` ON ...
  INNER JOIN `口座` ON ...
  INNER JOIN `ユーザー` ON ...
  WHERE
    `口座`.`id` = ? AND
    `決済リクエスト履歴`.`approved` = ? AND
    `決済リクエスト履歴`.`kind` = ? LIMIT 2
) subquery_for_count

これは端的に言うと「初回の決済かどうか」をチェックするという目的のためのものでした (ちなみに同僚の@ohbaryeがこれと類似のトピックについて過去に弊ブログで言及しています、チェックチェック〜！: オイ、そこのSELECT COUNT。余計な数え上げに意味なんかねえ - inSmartBank)。

このクエリは「対象カードによる初回の決済かどうか」というチェックのためにすべての決済に対して実行されているところがポイントでした。「初回決済」は文字通り1つのカードが高々1度しかしない体験であるため、このクエリを常に実行するのは無駄が多いと言えるでしょう。また、格納されているデータのパターンによってオプティマイザの挙動が変わるため、それが実行に際して長時間かかってしまう原因の一つのようでした。

なのでこの問題に対応するために先程作成した「カードの状態」を保持するサマリーテーブルに has_made_transactions という「決済を行ったことがあるかどうか」というcolumnを用意し、そこに状態を保存するようにしました。これを用いることにより、カードのIDによって has_made_transactionsを引き、偽である時だけ上記のクエリを実行してチェックする (そしてそれが真であれば has_made_transactions をtrueとして更新する) という処理にして、無駄なクエリの実行回数を劇的に減少させることに成功しました。

これどこかで見たな……？

そうです。ISUCONではこのような「都度実行されている重いクエリをサマリーテーブルに逃がす」という解法はポピュラーなものなのではないでしょうか。

例えば、

ざっくりと #isucon 2013年予選問題の解き方教えます : ISUCON公式Blog

MySQLにpublic_memosテーブルを追加してidとmemoを古い順に投入し、WHERE id BETWEEN ? AND ? でmemoのIDをとってくる

MySQLにpublic_countテーブルを追加して UPDATE public_count SET cnt = cnt + 1 で加算する

ISUCON 12 の予選に参加して、7位で本選進出を決めました - ぷらすのブログ

内容は、最新のスコアのみをキャッシュに保存して、そのキャッシュからランキングを生成するものでした。

ISUCON14 問題の解説と講評 : ISUCON公式Blog

また、最新以外のchair_locationsはここでのtotal_distanceを計算することにしか使われないことと、新しく椅子の位置情報が記録されるとき次のtotal_distanceは1つ前の位置情報とそれまでの total_distanceから計算できることに気がつけると、各椅子ごとに最新の位置情報と総走行距離を持つテーブルを作りUPSERTだけで管理できるようになり、ここでのクエリをはじめ様々なクエリをシンプルにすることができます。

などなど、サマリーテーブル関連だけでも類似の手法が大量に出てくることがわかります。

今回はたまたま「サマリーテーブルを用いる手法」が活用できたという感じでしたが、その他にも過去のISUCONで出てきた解法が実課題に活用できるケースはたくさんあるのではないかと思います *6。

このように「解き方の引き出しの数を増やす」ことで直面しているパフォーマンス問題に立ち向かうことができるようになるのではないでしょうか。ありがとう、ISUCON。

まとめ

パフォーマンス課題を退治する時には、

  • パフォーマンスの劣化やその箇所はモニタリングしておき気付けるようにする
  • パフォーマンスにまつわるメトリクスやデータを常に集めておき、その実測した事実をもとに原因にあたりを付け、ドメインが持つ特性を意識して仮説を立てて解決に取り組む
  • 経験したことのある解法を応用することで、実際のパフォーマンス問題を倒すことができる場合がある

という具合にISUCONでやっていることが業務に応用ができ (あるいは業務でやっていることがそのままISUCONに活きる *7 )、実際にできたという事例のご紹介でした。

まだ戦いは続く

そんなこんなでエラーバジェットは回復傾向にありますが、まだまだ改善できる余地はあるので今後もどんどんやっていきたいと思います。

株式会社スマートバンクではパフォーマンス改善に興味のあるサーバーサイドエンジニアを強く募集しています。

smartbank.co.jp

本筋と関係無い話題: それはそうと "Card find" はなんだったのか？

ところで上で原因の1つとして挙げていた Card find というクエリなのですが、このクエリは

SELECT `cards`.* FROM `cards` WHERE `cards`.`issuing_card_id` = ? LIMIT 1

と単純明解なものであり、かつ issuing_card_id には

CREATE TABLE `cards` (
  `id` bigint unsigned NOT NULL AUTO_INCREMENT,
  `issuing_card_id` varchar(30) CHARACTER SET utf8mb4 COLLATE utf8mb4_general_ci NOT NULL,
  ...
  PRIMARY KEY (`id`),
  KEY `index_cards_on_issuing_card_id` (`issuing_card_id`),
  ...
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_general_ci

と適切にindexが張られているため、EXPLAINも

*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: cards
   partitions: NULL
         type: ref
possible_keys: index_cards_on_issuing_card_id
          key: index_cards_on_issuing_card_id
      key_len: 1022
          ref: const
         rows: 1
     filtered: 100.00
        Extra: NULL

と「そりゃそうなるよね」というものでした。しかし時たまこのクエリが八面六臂の大暴れをすることがあり (ロックに阻害されているわけでもないのに数百msかかる)、その原因を考えていたときに、同僚の@ohbaryeから

key_lenめちゃデカいの気になりますね。というか他に怪しい箇所がわからず… 一般にインデックスページ（16KBサイズ）内に格納できる行数が減るので、より多くのインデックスページが必要となってメモリに乗り切らない（ディスクI/O起きる）とかの仮説は立てられるかも。 その場合、カラムサイズを小さくしてインデックスを再作成する必要がある…?

というヒント・仮説をもらいました。それは確かにありえそう、ということで

change_column :cards, :issuing_card_id, :string, limit: 30

という VARCHAR(30) にcolumnを切り詰めるというALTERを行った結果、以降時間を激しく食うクエリはなくなり一件落着、という形に落ち着きました。 そもそもRails (Active Record) のstring columnは

t.string :issuing_card_id, null: false

というふうに limit を指定しないと VARCHAR(255) というゴージャスなキャパシティを持つVARCHARを作るため、今回のように key_len がいたずらに大きくなる可能性があります。

今後こういった問題が再発しないとも限らないのでこのたび、string columnを作る際には limit オプションを必須とするRuboCopのCustom Copを導入することとしました:

class StringColumnWithLimit < RuboCop::Cop::Base
  MSG = 'DB migration file中でstring columnを使用する際は、limitオプションを指定してください。'

  def on_send(node)
    return unless in_migration_file?(processed_source.buffer.name)
    return unless node.method_name == :string

    has_limit_option = node.arguments.any? do |arg|
      arg.hash_type? && arg.pairs.any? do |pair|
        pair.key.sym_type? && pair.key.value == :limit
      end
    end

    return if has_limit_option

    add_offense(node.loc.selector)
  end

  private

  def in_migration_file?(file_path)
    file_path.include?('db/migrate')
  end
end

このCopを有効にしておくと、 limit がないstring columnの定義を検出した時に

t.string :name, null: false
  ^^^^^^ StringColumnWithLimit: DB migration file中でstring columnを使用する際は、limitオプションを指定してください。

という警告が出てくるようになります。これでちょっと安心ですね！

株式会社スマートバンクではCustom Copに興味のあるサーバーサイドエンジニアも募集しています。

smartbank.co.jp

*1:厳密にはプリペイドカード

*2:読者諸賢におかれましては「Webの1リクエストをさばくのに1.5秒ってめっちゃ遅くない！？」という指摘があるかと思うのですが、本筋の決済の他に不正利用チェックなど様々な処理をオンラインで行なわなくてはならないためこれくらいの目標設定となっています。もちろんこれが小さくなれば小さくなるほど良い、というのは言うまでもありません。

*3:株式会社スマートバンクでは「パフォーマンスミーティング」と称して隔週でシステムのメトリクスやパフォーマンスを眺める会があり、そこでの気付きでした

*4:プライマリキーで引ける、1件あたり一桁ミリ秒のクエリなのに呼ばれる回数が莫大なのでリーダーボードの上に来るということは良くあります

*5:もちろん不整合状態が発生する可能性はあるのでそのケアは別の手段により必要です。また今回は幸運にも仕様として「決済総額」を単調増加させることができましたが、場合によってはそうはならず金額を別途増減させたりする必要が出てくるでしょう。ここでの複雑性の上昇はトレードオフの関係にあると思います

*6:それもそのはず、ISUCONはだいたい先人が味わった実課題の苦しみをベースに問題になっていることが多いので……

*7:こちらの方が正当な筋であるようにも思います

We create the new normal of easy budgeting, easy banking, and easy living.
In this tech blog, engineers and other members will share their insights.