企業ページの表示速度を改善しました

こんにちは、バックエンドエンジニアの江間です。

ある日、一通のメッセージが届きました。

ネタバレをすると、ある API が実行している SQL がスロークエリになっており、そのレスポンスが返ってくるまで DOM のレンダリングが行われていない事が原因でした。

この記事では、 New Relic Application Performance Monitoring (APM) を使ったスロークエリの特定と、それを実際にどうやって解決したのか、更に速度改善を行ってAPIの平均レスポンスタイムを約5.78倍にした話についてを書いていきます。

目次

まずは当たりを付ける

該当のページは React でレンダリングを行っています。真っ白な画面になるということは DOM のレンダリングに時間がかかっている事が予想できます。

バックエンド視点で見ると、インフラ周りに問題はなく、 Fetch している API (アプリケーション側)が遅いのかな?と思えます。

次に、この現象が起こる特徴について

報告によると、プレスリリース配信数が多い企業の企業ページで、この現象が発生するらしい。

では実際にプレスリリース配信数が多い企業の企業ページで Fetch のタイミングを観察してみます。

レスポンスに4秒以上。流石にやばい。

このことから、プレスリリーステーブルを参照する API がスロークエリを叩いているのではないか?という当たりを付けることができました。

New Relic APM のどこを見るか

 New Relic APM を使ったパフォーマンス問題の分析は公式ドキュメントに記載されています。

あわせて読みたい
データベースとインスタンスレベルのパフォーマンス問題を解析する | New Relic DocumentationHow to use APM to identify if performance problems and errors are due to database performance, one or more hosts/instances or services, or both.

スロークエリトレースという便利な機能がありますが、 PR TIMES ではまだまだ多くのスロークエリがあるため、今回のようにピンポイントで情報が欲しい状況では、探し出すことが困難です。

そのためトランザクショントレースを使います。

APM > Transactions > 対象のAPI を選択し、 Transaction traces を見ます。

適当に選んだトレース結果から Trace details を見ます。

プレスリリーステーブル(t_release)への SELECT 文がスロークエリとなっていることがわかりました。

スロークエリの発見

まず実行されたクエリを見てみます。先程のトランザクショントレースからデータベースアイコンを押します。

SELECT release_complete_date 
FROM t_release 
WHERE company_id = [企業ID] AND … 
ORDER BY release_complete_date desc LIMIT 1;

このクエリは、プレスリリーステーブルから指定した企業の最初に配信したプレスリリースの配信日時を取得しています。

プレスリリーステーブルは、企業IDとプレスリリースIDを複合主キーとするt_release_primary_keyがあり、primary key (company_id, release_id)で定義されます。

また、プレスリリースの配信日時の INDEX としてt_release_release_complete_date_indexもあります。

テーブル構成(の中で必要な情報)はこちらです。

-- auto-generated definition
create table t_release
(
    company_id                                    integer                                                      not null,
    release_id                                    integer                                                      not null,
    release_complete_date                         timestamp,
    del_flg                                       boolean      default false,
    …
    constraint t_release_primary_key
        primary key (company_id, release_id)
);

create index t_release_release_complete_date_index
    on t_release (release_complete_date);

では New Relic で見つけたスロークエリに対して EXPLAIN を実行します。

プレスリリース数がそこまで多くない企業ではt_release_primary_keyが使われていて、 10 ms 以下で結果が返ってきます。

# EXPLAIN ANALYZE SELECT release_complete_date FROM t_release WHERE company_id = [企業ID] AND complete_flg = TRUE AND del_flg = FALSE AND stop_flg = FALSE AND release_media_list_only_flg = FALSE ORDER BY release_complete_date LIMIT 1;
                                                                    QUERY PLAN                                                                    
--------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=293.94..293.95 rows=1 width=8) (actual time=8.809..8.810 rows=1 loops=1)
   ->  Sort  (cost=293.94..294.09 rows=60 width=8) (actual time=8.807..8.808 rows=1 loops=1)
         Sort Key: release_complete_date
         Sort Method: top-N heapsort  Memory: 25kB
         ->  Index Scan using t_release_primary_key on t_release  (cost=0.43..293.64 rows=60 width=8) (actual time=0.060..8.688 rows=652 loops=1)
               Index Cond: (company_id = [企業ID])
               Filter: (complete_flg AND (NOT del_flg) AND (NOT stop_flg) AND (NOT release_media_list_only_flg))
               Rows Removed by Filter: 486
 Planning time: 0.159 ms
 Execution time: 8.834 ms
(10 行)

実行結果からt_release_primary_keyの INDEX を使ってcompany_idからフィルタリングをし、その後release_complete_dateでソートしていることがわかりました。

対して、プレスリリース数の多い企業では、t_release_primary_keyが使われずにt_release_release_complete_date_indexというインデックスが使われています。

# EXPLAIN ANALYZE SELECT release_complete_date FROM t_release WHERE company_id = [企業ID] AND complete_flg = TRUE AND del_flg = FALSE AND stop_flg = FALSE AND release_media_list_only_flg = FALSE ORDER BY release_complete_date LIMIT 1;
                                                                            QUERY PLAN                                                                             
-------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.43..210.35 rows=1 width=8) (actual time=2200.277..2200.278 rows=1 loops=1)
   ->  Index Scan using t_release_release_complete_date_index on t_release  (cost=0.43..512012.01 rows=2439 width=8) (actual time=2200.276..2200.276 rows=1 loops=1)
         Filter: (complete_flg AND (NOT del_flg) AND (NOT stop_flg) AND (NOT release_media_list_only_flg) AND (company_id = [企業ID]))
         Rows Removed by Filter: 632889
 Planning time: 0.161 ms
 Execution time: 2200.305 ms
(6 行)

どうやら、t_release_release_complete_date_indexインデックスを利用して ORDER BY をして WHERE 句の条件でフィルタリングしているようです。

その結果、 2200 ms かかってようやくデータが返ってきます。

解決方法

スロークエリに対する解決策として「インデックスを貼る」やり方が一般的であり、解決方法の一つとして複合 INDEX ((company_id,  release_complete_date))を貼る方法があります。

ただし、このクエリで取得したいデータ(=最初に配信したプレスリリースの配信日時)はデータが変更されることがないという特徴があります。
(なのに、わざわざスロークエリを実行してデータを取ってきていた!)

そのため今回は「新たにカラムを追加して、そこにデータを保存する」やり方を選択しました。

-- 最初に配信したプレスリリースの配信日時
ALTER TABLE m_company ADD COLUMN first_released_date DATE;

カラムの追加は安全に無停止で行いたかったので、 NOT NULL 制約は付けずにいます。

カラムを追加したい対象のm_companyテーブルはレコードが大量にあるので、 ACCESS EXCLUSIVE ロックを取得する ALTER TABLE は慎重に行う必要がありました。

もし一つの ALTER TABLE で NOT NULL 制約を付ける場合、 DEFAULT 句を付ける必要があり、全件 UPDATE が行われて長時間のロックになります。
それを避けてバッチ処理などで段階的に UPDATE を実行したとしても、NOT NULL 制約を付けるタイミングで NOT NULL が可能であるかを全件検査するので、長時間のロックを引き起こす可能性があります。(参考

これらのリスクを考慮して、first_released_dateカラムは NULL を許容したものとなっています。

アプリケーションの実装では、 API がリクエストされた時にfirst_released_dateカラムに値が入っている場合はそのまま返し、 NULL だった場合は一度その値をt_releaseテーブルから取得して、m_companyテーブルに保存してからレスポンスを返します。

// 最初に配信したプレスリリースの日付カラムがNULLの場合
if (strlen($company->first_released_date) === 0) {
    // プレスリリーステーブルから”最初に配信したプレスリリース”を取得
    $first_press_release = PressReleaseRepo::getCompanyFirstReleaseByCompanyId($company_id, $pdo);
    // ”最初に配信したプレスリリース”の配信日時を追加したカラムに入れる
    $company->first_released_date = $first_press_release->release_complete_date;
    // DBの更新処理をする(実際実行されるのは初回アクセス時だけ)
    CompanyRepo::updateFirstReleasedDate($company, $pdo);
}

計測結果(スロークエリの解消)

App performance の結果を見てみます。

グラフに紫色で表示されるt_releaseテーブルのスロークエリは解決出来ました 🙌

しかし、スピードはそこまで上がっていないようです。

考察(スロークエリの解消)

実は、このスロークエリの改善と同時に、別の部分も改修しました。

その際に SELECT を余分に呼び出してしまっているため、遅くなっているようです。

SQL実行時間呼び出し回数(改修前)呼び出し回数(改修後)
企業有効判定SQL29.021 ms1回1回
企業情報取得SQL0.743 ms1回
企業有効判定&企業情報取得SQL29.021 ms1回

※実行時間は psql から実行した結果であるので、New Relic の実行時間とは異なったデータになっています。

また、表を見ると「企業情報取得SQL」よりも「企業有効判定SQL」が遅いことがわかります。速度的にも INDEX が効いていないだろう事が予想が出来ます。

いい感じにスピードアップする

さて、ここから更に速度改善するために

  • 不要な SQL の呼び出しを削除する
  • 企業有効判定が効率的に行える INDEX を貼る

の2つの改修を行います。

不要な SQL の呼び出しを削除する

「企業情報取得SQL」を「企業有効判定SQL」と合わせた「企業有効判定&企業情報取得SQL」のSQLへ改修しました。しかし、「企業有効判定SQL」の呼び出しを消すことを忘れていました。

そのため、不要となった「企業有効判定SQL」を呼び出すコードを削除しました。

結果

倍近く速度改善されました!

企業有効判定が効率的に行える INDEX を貼る

「企業有効判定&企業情報取得SQL」の実際のSQLはこちらです。

SELECT m_company.* 
FROM m_company 
  INNER JOIN m_company_user 
    ON m_company_user.company_id = m_company.company_id 
WHERE m_company.company_id = [企業ID]
  AND m_company.del_flg = FALSE
  AND (m_company_user.regist_status = TRUE OR m_company.registmail_send = 1);

企業有効判定では、企業テーブル(m_company)と企業ユーザーテーブル(m_company_user)を確認しています。

企業テーブルと企業ユーザーテーブルは、企業IDで紐付いた親テーブルと子テーブルの関係です。しかし実際は外部キー制約も INDEX もありませんでした。

-- auto-generated definition
create table m_company_user
(
    company_user_id   serial
        constraint m_company_user_pkey
            primary key,
    company_id        integer  default 0     not null,
    …
);

そのため先程のクエリを EXPLAIN で調べてみると Seq Scan が行われている事が確認できます。

# EXPLAIN ANALYZE SELECT m_company.* FROM m_company INNER JOIN m_company_user ON m_company_user.company_id = m_company.company_id WHERE m_company.company_id = [企業ID] AND m_company.del_flg = FALSE AND (m_company_user.regist_status = TRUE OR m_company.registmail_send = 1);
                                                            QUERY PLAN                                                             
-----------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.29..4449.61 rows=99 width=1593) (actual time=2.787..21.173 rows=102 loops=1)
   Join Filter: (m_company_user.regist_status OR (m_company.registmail_send = 1))
   ->  Index Scan using m_company_pkey on m_company  (cost=0.29..8.31 rows=1 width=1593) (actual time=2.496..2.498 rows=1 loops=1)
         Index Cond: (company_id = [企業ID])
         Filter: (NOT del_flg)
   ->  Seq Scan on m_company_user  (cost=0.00..4440.04 rows=101 width=5) (actual time=0.286..18.622 rows=102 loops=1)
         Filter: (company_id = [企業ID])
         Rows Removed by Filter: 89021
 Planning time: 0.273 ms
 Execution time: 21.255 ms
(10 行)

ということでm_company_user.company_idに INDEX を貼ります。

CREATE INDEX ON m_company_user (company_id);

INDEX を貼った後、もう一度 EXPLAIN を実行します。

# EXPLAIN ANALYZE SELECT m_company.* FROM m_company INNER JOIN m_company_user ON m_company_user.company_id = m_company.company_id WHERE m_company.company_id = [企業ID] AND m_company.del_flg = FALSE AND (m_company_user.regist_status = TRUE OR m_company.registmail_send = 1);
                                                                      QUERY PLAN                                                                      
------------------------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.71..19.63 rows=2 width=1606) (actual time=0.070..0.124 rows=10 loops=1)
   Join Filter: (m_company_user.regist_status OR (m_company.registmail_send = 1))
   Rows Removed by Join Filter: 6
   ->  Index Scan using m_company_pkey on m_company  (cost=0.29..8.31 rows=1 width=1606) (actual time=0.011..0.013 rows=1 loops=1)
         Index Cond: (company_id = [企業ID])
         Filter: (NOT del_flg)
   ->  Index Scan using m_company_user_company_id_idx on m_company_user  (cost=0.42..11.30 rows=2 width=5) (actual time=0.038..0.068 rows=16 loops=1)
         Index Cond: (company_id = [企業ID])
 Planning time: 0.558 ms
 Execution time: 0.276 ms
(10 行)

無事に Index Scan が使われるようになりました。

実際の計測はこちら

かなり早くなりました 🙌

計測結果(最終)

New Relic

各改善後のAPIのレスポンスタイムを表にまとめました。

改善前スロークエリの改善不要な SQL の
呼び出しを削除
INDEX を貼る
1時間の平均レスポンスタイムの
最大値※1
336 ms223 ms114 ms68 ms
平均レスポンスタイム※2222 ms177 ms105 ms38.4 ms

※1 下で計測した平均レスポンスタイムと同じ期間内での最大値になります。
※2 最大1週間となる任意の期間が対象です。改善のリリースまで1週間経っていない場合などは、より短い期間での計測になっています。

1時間の平均レスポンスタイムの最大値では約4.94倍、平均レスポンスタイムでは約5.78倍早くなりました!

Light House

Light House の結果はこちらになります。

Performance が 51 から 67 に向上しました!

APIが早くなったこともありますが、どうやらそれ以外にも今回作成した INDEX が上手く使われる様になって、全体的にパフォーマンスが上がったようです。

Network Timing

Light House の結果はこちらになります。

4.75 s もかかっていたレスポンスが 98 ms になりました!

レスポンスタイムが 100 ms 以下なので、十分なスピードになったかと思われます。

終わりに

今回はスロークエリから始まり、パフォーマンスの改善まで行いました。

スロークエリの発見やパフォーマンスの改善では New Relic を活用すると楽に行えるので、ご参考になれば幸いです。

最後に、バックエンドエンジニア(中途・インターン)を募集中です!

もしご興味がありましたらご応募下さい!

株式会社PR TIMES
技術の力で社会に価値を発揮したいバックエンドエンジニアを募集! - 株式会社PR TIMES
技術の力で社会に価値を発揮したいバックエンドエンジニアを募集! - 株式会社PR TIMES株式会社PR TIMESでは現在03-3. 開発本部 バックエンドエンジニアを募集しています。
株式会社PR TIMES
執行役員CTO直下で、エンジニアとして実力をあげたい学生インターンを募集! - 株式会社PR TIMES
執行役員CTO直下で、エンジニアとして実力をあげたい学生インターンを募集! - 株式会社PR TIMES株式会社PR TIMESでは現在20-5. 開発本部 バックエンドエンジニア 学生インターンを募集しています。

この記事を書いた人

株式会社PR TIMES 開発本部 バックエンドエンジニア

目次
閉じる