1. 改訂履歴

版 改訂日 変更内容
1.0 2018/04/11
2017年度版として新規作成
2.0 2019/03/15
2018年度版として主に以下の章を加筆修正
- 4章 性能トラブルを防ぐために考慮すべき設計ポイント
パラメータチューニングソフトウェアの評価
性能影響調査(インデックス再作成、バックアップ等)
- 5章 性能状態を把握するための監視
待機イベント発生回数の取得
- 6章 ケーススタディ
インデックス関連のトラブル事例
3.0 2019/04/16
2019年度版として以下の章を加筆
- 6章 ケーススタディ
インデックス関連のトラブル事例

2. ライセンス

本作品はCC-BYライセンスによって許諾されています。 ライセンスの内容を知りたい方は こちら でご確認ください。 文書の内容、表記に関する誤り、ご要望、感想等につきましては、PGEConsのサイト を通じてお寄せいただきますようお願いいたします。

  • Eclipseは、Eclipse Foundation Incの米国、およびその他の国における商標もしくは登録商標です。
  • IBMおよびDB2は、世界の多くの国で登録されたInternational Business Machines Corporationの商標です。
  • Intel、インテルおよびXeonは、米国およびその他の国における Intel Corporation の商標です。
  • Javaは、Oracle Corporation 及びその子会社、関連会社の米国及びその他の国における登録商標です。 文中の社名、商品名等は各社の商標または登録商標である場合があります。
  • Linux は、Linus Torvalds 氏の日本およびその他の国における登録商標または商標です。
  • Red HatおよびShadowman logoは、米国およびその他の国におけるRed Hat,Inc.の商標または登録商標です。
  • Microsoft、Windows Server、SQL Server、米国 Microsoft Corporationの米国及びその他の国における登録商標または商標です。
  • MySQLは、Oracle Corporation 及びその子会社、関連会社の米国及びその他の国における登録商標です。 文中の社名、商品名等は各社の商標または登録商標である場合があります。
  • Oracleは、Oracle Corporation 及びその子会社、関連会社の米国及びその他の国における登録商標です。 文中の社名、商品名等は各社の商標または登録商標である場合があります。
  • PostgreSQLは、PostgreSQL Community Association of Canadaのカナダにおける登録商標およびその他の国における商標です。
  • Windows は米国 Microsoft Corporation の米国およびその他の国における登録商標です。
  • TPC, TPC Benchmark,TPC-C, TPC-E, tpmC, TPC-H, QphHは米国Transaction Processing Performance Councilの商標です
  • その他、本資料に記載されている社名及び商品名はそれぞれ各社が 商標または登録商標として使用している場合があります 。

3. はじめに

3.1. PostgreSQLエンタープライズコンソーシアムとWG3について

PostgreSQLエンタープライズコンソーシアム(略称 PGECons)は、PostgreSQL本体および各種ツールの情報収集と提供、整備などの活動を通じて、ミッションクリティカル性の高いエンタープライズ領域へのPostgreSQLの普及を推進することを目的として設立された団体です。

PGECons 技術部会ではPostgreSQLの普及に資する課題を活動テーマとし、3つのワーキンググループで具体的な活動を行っています。

  • WG1（新技術検証ワーキンググループ）
  • WG2（移行ワーキンググループ）
  • WG3（課題検討ワーキンググループ）

これら3つのワーキンググループのうち、WG1、WG3については 2015 年度まではそれぞれ、「性能ワーキンググループ」、「設計運用ワーキンググループ」という名称で活動してきました。2016年度は、従来の活動領域を広げる意図のもとでそれらを再定義し、上記のような名称に改めました。

これに伴い、WG3ではPostgreSQLの設計運用を中心としたさまざまな課題の解決のための調査検証を行い、PostgreSQLが広く活用される事を推進していくこととしました。

3.2. 本資料の概要と目的

本資料はWG3の2018年度の活動として PostgreSQL における性能トラブルについて、調査・検討した結果をまとめたものです。

WG3では2017年度から継続して性能トラブルについて調査を実施しております。 2017年度の調査結果を踏まえて、2018年度は性能トラブルへの『予防』 『検知』 『対処』について次の情報を調査・拡充しています。 『予防』の観点としてはPostgreSQLのパラメータを自動チューニングする外部ツールについて調査・検討した結果を紹介しています。 また、PostgreSQL利用者が懸念されることが多い、インデックス再作成、オンラインでのバックアップ取得、自動Vacuumによる性能影響について調査した結果を紹介しています。 『検知』の観点では、外部ツールを用いて待機イベントの発生回数を調査する方法を追加しています。 『対処』の観点では、インデックスに関連した過去のトラブル事例を取集し、取得情報を使用した調査方法を追加しています。

以上の内容を本資料にまとめる事で今後のPostgreSQL運用において、性能トラブル対策の一助となる情報を提供することを目的としています。

3.3. 本資料の構成

本資料は次の構成となっております。

分類 章タイトル 概要
予防 4.性能トラブルを予防するために考慮すべきデータべース設計のポイント 性能トラブルを発生させないため設計時に考慮すべきポイントや性能トラブルを発生させないために必要となるノウハウを紹介
検知 5.性能状態を把握するための監視 正常稼働中から取得しておくべき、性能状態を把握するために必要な監視情報や性能トラブルが発生した時の各監視情報での調査観点も紹介
事例 6.ケーススタディ 過去の性能トラブル事例をもとに、取得情報を使用した調査方法を紹介

3.4. 想定読者

本資料の読者は以下のような知識を有していることを想定しています。

  • DBMSを操作してデータベースの構築、保守、運用を行うDBAの知識
  • PostgreSQLを利用する上での基礎的な知識

4. 性能トラブルを予防するために考慮すべきデータべース設計のポイント

4.1. 本章の記載内容、方針について

PostgreSQLでデータベースを新たに設計していくにあたり 性能トラブルとして分類される事例や報告をもとにして、 トラブルの予防に役立つ対策となるようなポイントをまとめました。

本章ではデータベース設計の流れとして以下のデータベース設計の記事 [1] を参考とし、 概念設計、論理設計、物理設計の３つの段階について 性能との関連が深くなる論理設計、物理設計の２つを取り上げます。

その他、システムが実稼働した後のために考慮しておくべき運用管理の部分についても運用の設計と定義し、 以下の図に沿った流れで検討項目をピックアップしポイントを記載していきます。

データベース設計の流れ

各工程や検討項目については参考となる資料が公開されているものも多いため ここでの詳細な解説は割愛し、概要と参考情報のリンクを付与する形で紹介していきます。

参考情報

文献番号 タイトル URL 概要
[1]
初めてのデータベース設計　第1回　データベース設計とは http://gihyo.jp/dev/feature/01/database/0001 概念設計、論理設計、物理設計の３つの段階について紹介

4.2. 論理設計

論理設計では概念設計で作成したER図などの概念モデルをリレーショナルモデルなどの論理モデルに変換します。 その際に性能に関わる検討項目として正規化をどこまで実施するかという点が挙げられます。


4.2.1. 論理モデルの作成/正規化

概念設計で作成した概念モデルをリレーショナルデータベースで取り扱うためには正規形と呼ばれる形式に変換を行います [2] 。 これを論理モデルの作成/正規化と呼びます。

考慮すべきポイント

正規化を行えばデータの追加・更新・削除などに伴うデータの不整合や喪失が起きるのを防ぎ、メンテナンスの効率を高めることができます。 正規化の段階には第1～第5正規形およびボイスコッド正規形があります。

深く進める程データが細分化されそれぞれの管理や更新が容易になりますが、 検索時にはテーブル結合が必要となるため、検索の範囲や条件が複雑なSQLのパフォーマンスが低下してしまいます。 テーブルの数を抑え検索のパフォーマンスを向上させるためにあえて正規化の程度を落とすことも、性能面で考慮すべきポイントなります [3] 。

考慮漏れによる起こりうる性能トラブルの例

機械的に正規化を進めた結果、都道府県、性別など非常に細かいレベルまで正規化を実施し、結果として結合対象の表が増え、結合時のコストが問題になるパターンがあり得ます。

都道府県や性別のように新たな項目が追加されたり変更が起こりえないと考えられるものは正規化を崩し検索のパフォーマンスを優先させることが有効です。

参考情報

文献番号 タイトル URL 概要
[2]
OSS-DB入門　第4回　データベースの正規化 https://oss-db.jp/measures/dojo_info_04.shtml データベースの正規化について紹介
[3]
データモデリング・テクニック https://www.slideshare.net/HidekatsuIzuno/ss-67532977 パフォーマンス改善のために正規化を崩すこと、非正規化する場合の一例などを紹介

4.3. 物理設計

物理設計ではテーブル定義の設計からHW構成とサイジングの物理的な設計、パラメータの設計までを実施します。

各フェーズそれぞれで検討すべき項目が多く突き詰めていくと非常に奥が深いため、ここでは見落としがあると性能問題に発生しやすいポイントを取り上げます。


4.3.1. テーブル設計

正規形に変換したテーブルを、実際にPostgreSQLにおけるテーブル定義にあてはめていく工程です。

考慮すべきポイント

テーブルを設計/定義するにあたって性能面に影響する、考慮すべきポイントとして以下の3つの要素が挙げられます。

  1. データ型の選択と検討。各列に適切なデータ型を利用する(数値データ型など)
    数値であれば精度の高さから正確な計算のためにnumeric型が採用されることがありますが、性能面でいえばint型やreal型と比較し明らかな差が出ます [4] 要件によって整数しか登場しない場合、ある程度の丸め誤差が許容される場合などint型やreal型を選択すべきです
  2. HOTを有効に活用できるようFILFACTORの値を検討する [5]
    デフォルトでは100に設定されていますが、UPDATEが多いケースでは少し変えるだけで効果が出ます [6]
  3. パーティショニングによるテーブル分割を活用する
    データサイズが大きくなる場合、また一定の範囲を検索する際にシーケンシャルスキャンが避けられない場合、パーティションの利用は参照性能の向上に有効です [7] 特にPostgreSQL10では宣言的パーティションが実装され課題であった挿入時の性能ネック、トリガによる管理の煩雑さが解決され利用する価値が大きく向上しました [8]

考慮漏れによる起こりうる性能トラブルの例

UPDATEが多いシステムにおいてFILFACTORをデフォルトである100のまま運用していると、データの規模が大きくなるにつれてある時UPDATEが大幅に遅延するという問題が発生することがあります。

参考情報

文献番号 タイトル URL 概要
[4]
初めてのデータベース設計　第4回　データ型 http://gihyo.jp/dev/feature/01/database/0004?page=1 データ型の選択における概要と、数値型の特性について
[5]
HOTの上手な使い方 https://lets.postgresql.jp/documents/tutorial/hot3 HOTとFILFACTORについて
[6]
FILLFACTORによる性能改善 http://kyabatalian.hatenablog.com/entry/2017/12/16/160754 FILFACTORを100と80に設定した場合の検証結果
[7]
パーティショニングの性能検証結果を踏まえて、性能に影響を与える要素について考察 https://www.pgecons.org/wp-content/uploads/PGECons/2013/WG1/wg1-2013-report.pdf#page=30 パーティショニングによる検索性能の具体的な向上を示す検証結果
[8]
PostgreSQL 10の宣言的パーティション https://www.ntt-tx.co.jp/column/postgresql_blog/20171005/ PostgreSQL10で実装された宣言的パーティションの改善点について

4.3.2. インデックス設計

テーブルのデータ型やパーティショニングを検討・設計した後、想定される検索や結合の条件を精査し、対象となる列にインデックスを定義していきます。

考慮すべきポイント

闇雲なインデックスの付与は更新処理の性能低下にもつながるため、定義すべき列の選択について以下の観点で精査していきます。

  • 検索SQLのうち以下の対象となる列に作成する
    1. WHERE句の条件
    2. テーブル結合の条件
    3. ORDER BYやGROUP BYに指定される列
  • カーディナリティの高い列に作成する

その他、B-Treeインデックスにおいては更に性能を向上させられる応用的な使い方もあり [9] 、 例として部分インデックスの利用で大幅に性能を向上させられるケースもあります [10] 。

また、定義したインデックスが実際にはあまり使われていないと更新性能の足かせとなってしまいます。 実運用に入ってからのチューニングとはなりますが、統計情報を参照し不要なインデックスを削除することも全体的なパフォーマンス向上のために必要です [9] 。

インデックススキャンは抽出する件数によって、テーブルスキャンよりも遅くなる場合があります。どのような状況で逆転が起こるか検証しましたので、 2019年度WG3活動報告書 性能トラブル調査編 を参照してください。

考慮漏れによる起こりうる性能トラブルの例

意外と現場で起こりうるのがレコード数の多いテーブルに対するインデックスの定義漏れであり、 seq scanが実行されCPU使用率が高騰してしまうなどのトラブルに繋がることがあります。 一定規模のテーブルに対するインデックスの定義漏れ、検討漏れに注意が必要です。

参考情報

文献番号 タイトル URL 概要
[9](1, 2)
PostgreSQLのインデックス・チューニング by Tomonari Katsumata https://www.slideshare.net/InsightTechnology/dbts-osaka-2014-b23-postgresql-tomonari-katsumata B-treeインデックスの有効活用のポイントや、利用状況の確認の仕方など
[10]
PostgreSQL SQLチューニング入門　実践編 https://www.slideshare.net/satoshiyamada71697/postgresql-sql 部分インデックスを用いて性能改善させる実践例

4.3.3. ハードウェアのサイジング

データの格納に必要なストレージサイズの見積もり、処理性能を満たすために必要なCPUとメモリの算定を実施します。

考慮すべきポイント

ストレージサイズの見積もりは決まった計算式で算出することができますが [11] 、CPUとメモリのサイジングは総処理数をもとに、実機を用いた検証でレスポンスタイムを確認して見積もる必要があります。

考慮漏れによる起こりうる性能トラブルの例

性能問題が発生した際に、パラメータやSQLの実行計画に特段問題が見当たらず、HWのスペックが絶対的に不足しているというケースがあります。

ロングトランザクション等はなく１つ１つのSQLは100ms以内に終わるものでも、CPUの性能に対し同時処理数が多い場合はパラメータ等では対処できず、物理的なスペック増強による対処が必要となります。

参考情報

文献番号 タイトル URL 概要
[11]
PostgreSQL でのデータベース構築の際に必要となる物理設計のポイント https://lets.postgresql.jp/documents/tutorial/gihyo_rensai/5 ストーレジサイズの見積もりのための計算式について

4.3.4. ディスクの構成・ファイルの配置検討

PostgreSQLのデータベースを構成する各種ファイルの配置と、それに伴うディスクの構成を検討します

考慮すべきポイント

PostgreSQLのファイル構成はデータベースクラスタという単位で通常PGDATAという環境変数で一つのディレクトリ内に配置されます [12] 。

それぞれの領域に様々な処理に伴うI/Oが発生しますが [13] 、性能面を考慮する場合に特に推奨されるのがWALの保存領域をわけることであり、 WALの書き込みI/O待ちを発生させないことが性能に直結します。

考慮漏れによる起こりうる性能トラブルの例

PostgreSQLのインストール時にPGDATA配下のディレクトリを同一ディスクの同一の論理領域にまとめて構成した場合、 WALの書き込み待ちにより更新性能が出ないケースがあります。その場合WAL領域だけでも別のディスクに配置することで大きく性能が改善される可能性があります。

参考情報

文献番号 タイトル URL 概要
[12]
データベースファイルのレイアウト https://www.postgresql.jp/document/9.5/html/storage-file-layout.html PostgreSQLのPGDATA以下のディレクトリ構成について。利用するVerに応じたドキュメントを参照してください(特に10以降で名称の変更などあり)
[13]
実践！PostgreSQL運用 https://www.postgresql.jp/sites/default/files/2017-01/T5_jissen_PostgreSQL_unyou.pdf ディスク設計の考え方と、各領域に発生するI/Oについても整理/解説

4.3.5. パラメータ設計

PostgreSQLの設定パラメータであるpostgresql.confの設定内容を検討、決定していきます。

考慮すべきポイント

PostgreSQLのパラメータについてはこう設定しておけばよい、という普遍的な設定値はありませんが、 いくつかのパラメータについてデフォルトのままで運用していてトラブルが発生してしまう事例があります。

新しいVerほどデフォルトパラメータも考慮されつつありますが、最低限見直すべきパラメータ [14] [15] は存在するため、参考情報のリンクをもとに値を精査していく必要があります。

考慮漏れによる起こりうる性能トラブルの例

  • PostgreSQLを内部DBとして利用するSWパッケージ製品について、SWと同時にPostgreSQLもインストールされるがpostgresql.confのパラメータは設定されず、利用者が構築時に設定を怠るとデフォルトで運用され性能が出ないケースがある
  • checkpoint_segmentsの値をデフォルトで運用しており、チェックポイントの頻発により性能が劣化してしまう。チェックポイント間隔の調整が必要に [16]
  • ODBCドライバの利用において、Level of rollback on errorsがデフォルトの設定でSQL実行の度にSAVEPOINTとRELEASEが実行されるよになっており性能劣化を引き起こしてしまうケースがある

参考情報

文献番号 タイトル URL 概要
[14]
Tuning Your PostgreSQL Server/ja https://wiki.postgresql.org/wiki/Tuning_Your_PostgreSQL_Server/ja デフォルトから見直すべき基本的なパラメータについて解説
[15]
PostgreSQLの性能関連パラメータの設定支援ツール PGTuneの紹介 https://edoshimafukurou220882089.wordpress.com/2019/02/17/posgresqlの性能関連パラメータの設定支援ツール-pgtuneの紹介 HWリソースや接続数、アプリケーションの種類を指定すると、性能観点で変更すべきパラメータの推奨値を提示してくれるWebサイトの紹介
[16]
まずやっとく PostgreSQLのチューニング http://dbstudychugoku.github.io/pdf/20140713_postgre_tuning.pdf チェックポイント間隔の調整について解説

4.4. 運用の設計

データベースの一般的な設計としては以上となりますが、データベースを安定稼働させるためには運用管理の部分も検討が必要です。

ここでは運用の設計として主にVACCUMの取り扱いとDB監視(性能情報、特にスロークエリとロングトランザクション)について検討していきます。


4.4.1. VACUUMの取り扱い

PostgreSQL特有の性質であり運用上必ず必要となるVACUUMの実施タイミングについて検討していきます。

考慮すべきポイント

PostgreSQL特有の問題として定期的なVACUUMの実施によるガベージコレクションが必須となります [17] 。

autovaccumをONにしていれば(8.3以降はデフォルトでON)テーブルの状態を監視して、 然るべきタイミングに自動でVACUUMを実施してくれますが、 データベースの利用状況によっては手動でのVACUUM実施を検討する必要があります。

例として頻繁に更新が発生するテーブルではXID周回防止処理 [18] がネックとなった事例があり、 FREEZE処理のために夜間など、システムが利用されてないタイミングでVACUUMを手動実行させるべき場合があります。

また、APやシステムの設計によってはロングトランザクションやセッションの残存により ロックが取得できず、autovacuumが滞り性能が劣化していった事例などもあります。

そのようなケースではAPの設計とも併せて、VACUUMのタイミングを考慮する必要があります。

考慮漏れによる起こりうる性能トラブルの例

  • 頻繁に更新のあるテーブルに対してautovacuum発生時のXID周回防止処理が性能ネックに。だんだんと目に見える処理遅延につながるケースがある。VACUUM FREEZEを夜間で手動実行するなどの対処が必要となる
  • APの作りに不備がありロングトランザクション、セッション残存でautovacuumが阻害されてしまうケースがある。この場合、時間とともに性能劣化がどんどん進んでしまうことに

参考情報

文献番号 タイトル URL 概要
[17]
PostgreSQLの運用・監視にまつわるエトセトラ https://www.slideshare.net/hadoopxnttdata/postgresql-operations-monitoring-etc VACUUMの効用/副作用、実施方法や考えることなどを資料内で解説
[18]
PostgreSQL: XID周回問題に潜む別の問題 https://www.slideshare.net/hadoopxnttdata/postgresql-xid-wraparound-another-issue PostgreSQLのXID周回問題にについて解説

4.4.2. DB性能情報の監視

DB監視ではDBやOSの様々な情報(ログやCPU/メモリの利用率、統計情報など)を監視し、障害や異常を事前に察知することが目的となります。

ここでは性能トラブルを早めに察知するために、性能情報を監視することを検討していきます。

考慮すべきポイント

導入前の評価では問題がなくても、実運用に入ってから思わぬ原因でスロークエリ、ロングトランザクションが発生することがあります。 事例の中で見えてくるポイントとしては急激な性能劣化が発生するのではなく、だんだんと処理時間が伸びていっているパターンが多いです。

そのため、初期のスロークエリをいかに素早く検知し、問題を特定できるかが非常に重要です。

基本的なスロークエリの検知方法としてはlog_min_duration_statementの設定でログに出力させることができますが、 クエリの処理時間だけでなくCPUの高騰、メモリの枯渇等がシグナルとなる場合もありますので これらを総合的に監視できるような運用、施策を検討することが性能トラブルへの一番の予防となります。

性能トラブルを予防するために考慮すべきデータべース設計のポイント で挙げた設計ポイントを考慮していっても実運用で発生する問題は予測しきれないものもあるため、 この監視を充実させることこそ性能トラブルを発生させない一番の対策となります。

そのため本報告書では監視について別途 性能状態を把握するための監視 に切り出し記載しています。 詳細は 性能状態を把握するための監視 の記述を参照してください。

考慮漏れによる起こりうる性能トラブルの例

監視を実施しないことが直接の性能トラブルの原因となることはありませんが、監視をすることで早期対処ができる可能性があります [19] 。

参考情報

文献番号 タイトル URL 概要
[19]
DBAサバイバルガイド　pg_stats_reporter で性能トラブルを洗い出せ https://qiita.com/masudakz/items/b3226ba0c1753ad1538d pg_statsinfoとpg_stats_reporterを用いて性能監視を行い、性能トラブルの予兆に気づき事前に対処した事例の紹介

4.5. その他

データベースの設計、運用の設計とは観点が異なりますが、性能トラブルを予防するにあたり留意すべきその他の検討要素を記載します。


4.5.1. 統計情報の取り扱い

性能トラブルのパターンとして統計情報が問題となるケースがあります。 その場合は実行計画や統計情報を制御する外部ツールの導入も検討すべきポイントとなります。

考慮すべきポイント

性能トラブルとして急に処理が遅くなった、という場合に実行計画が適切でないものに変動されてしまった、その原因として統計情報が問題となっているケースがあります。

以下のような実行計画の変動により性能が悪化した事例について、いずれも統計情報が最新でなくプランナによる推定コストが低く見えてしまったことが原因となっており、 最適な実行計画を選択してもらうには統計情報を適宜最新化することが必要です。

  • HashJoinが選択されていたクエリが、NestedLoopが選択されてしまう
  • HashJoinを用いるクエリについて、Hash作成対象テーブルが変更され、より件数の多いテーブルが選択されてしまう
  • 全件検索が必要なテーブルにインデックススキャンが選択されてしまう

定期的なANALYZEの実行が有効な手段となりますが、データの傾向として最適なプランがわかっている場合は pg_hint_plan(PostgreSQLでヒント句を実装する外部ツール)の導入による実行計画の固定、またはpg_dbms_stats(PostgreSQL の統計情報管理ツール)による統計情報の固定化も有効です [20] 。

考慮漏れによる起こりうる性能トラブルの例

実運用に入りしばらくしてからバッチ処理が大きく遅延するケースとして、ANALYZEの実行が運用に組み入れられておらず、上記ポイントで挙げたような実行計画の変動が発生してしまっている場合があります。

ANALYZEの実行により処理が改善される可能性もありますが、処理の特性により対象テーブルの件数が大きく変わる場合などは、pg_hint_planを導入し都度、Hash対象テーブルを明示的に指定するなどの対処も効果的です。

参考情報

文献番号 タイトル URL 概要
[20]
2015 年度 WG3 活動報告書　データベースツール編 https://www.pgecons.org/wp-content/uploads/PGECons/2015/WG3/PGECons_2015_WG3_DBTools.pdf#page=48 実行計画と統計情報の制御に関連するツールの紹介
orphan:

4.6. 性能影響調査

4.6.1. autovacuumの処理時間とパラメータチューニング

4.6.1.1. 概要

■ autovacuumの仕組み

PostgreSQLのVACUUMは、削除された行や更新によって不要となった行の領域を再利用できる状態に変更します。 VACUUMは利用者がコマンドで実行することが可能ですが、VACUUMを自動的に実行するautovacuumを備えておりますので、多くの場合では利用者が意識していなくて、自動的にVACUUMが行われる仕組みになっています。

このautovacuumは定期的にテーブル状態を監視し、不要領域が閾値(autovacuum_vacuum_scale_factor：デフォルト値はテーブルサイズの20%)を超えた場合にVACUUMとANALYZEを行います。 また、autovacuumがVACUUMを実行する際にも各ワーカーでのコスト値の合計がautovacuum_vacuum_cost_limitに達した時にautovacuum_vacuum_cost_delayの間作業を中断することで、I/O負荷が高負荷にならないように動作します。 不要領域の回収速度を制御するこれらのパラメータは、テーブル毎に設定変更可能です。 (※下図参照)


autovacuumのチューニングパラメータ

■ autovacuumを利用する上での課題

不要領域の発生速度がautovacuumの回収速度を上回っている場合では不要領域が溜まっていく一方となり、テーブルは肥大化してくことになります。 肥大化するテーブルではパラメータチューニングにより、autovacuumの処理性能を向上させる必要があるのですが、現状ではautovacuumのパラメータ設定値の設計方法に関する情報が不足していると考えます。

■ 検証の目的

今回の検証では更新によって発生する不要領域に対し、テーブルサイズの肥大化を引き起こさずにautovacuumで適切に回収できるようにするために、autovacuum_vacuum_cost_delayとautovacuum_vacuum_cost_limitを用いたパラメータチューニング方法を明確にすることを目的とします。


表 4.1 パラメータ説明
パラメータ デフォルト値 パラメータ説明
autovacuum_vacuum_cost_limit 200
autovacuumに使用されるコスト限界値を指定します。
(デフォルトの)-1が指定されると、vacuum_cost_limitの値が使用されます。
この値は、実行中のautovacuum workerプロセスが複数存在する場合workerプロセスすべてに比例分配されます。
テーブル毎に設定した場合には、そのテーブルで動作するautovacuum workerプロセスの上限値となります。
autovacuum_vacuum_cost_delay 20
autovacuumに使用されるコスト遅延値を指定します。
-1に指定されると、vacuum_cost_delayの値が使用されます。
累積されたコストが(autovacuum_vacuum_cost_limitで指定された)限度に達すると、
autovacuum_vacuum_cost_delayで指定された時間スリープしていますので、短くする程I/O負荷が上がります。

4.6.1.2. 検証内容

本検証では、以下の内容を実施しました。

  1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定
    autovacuumのチューニング対象とするパラメータの設定値を変更していき、それぞれの設定値ごとにautovacuumによる不要領域の回収速度を測定します。
    (autovacuumによる不要領域の回収速度をautovacuum処理性能と称します。)
  2. autovacuumのパラメータチューニングの効果を測定
    定期的に更新処理を行い、不要領域が発生し続けるテーブルに対し、1で見積もったautovacuum処理性能からパラメータ値を設定し、
    期待通りの動作が実現するかをテーブルの不要行数とテーブルサイズの推移から確認します。

4.6.1.3. 検証方法

「1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定」は次のように実施

a. 1000万件のデータが格納されたテーブル(※1)を作成
b. 各パラメータ（autovacuum_vacuum_cost_limit, autovacuum_vacuum_cost_delay）に値を設定
c. テーブルにUPDATEコマンドを実行し、テーブルの25%(250万件)の不要領域を作成
d. PostgreSQLのログメッセージより、autovacuumの処理時間を確認
※1 HOT（Heap-only tuples）の効果を抑止するために更新対象の列にインデックスを作成。

「2. autovacuumのパラメータチューニングの効果を測定」は次のように実施

a. 1,000万件のデータが格納されたテーブル(※1)を作成
b. テーブルにUPDATEコマンドを実行し、テーブルの25%(250万件)の不要領域を作成
c. 1分間ごとにテーブルの3.125%(312500行)を更新するUPDATEコマンドを実行
autovacuum処理性能を上回る速度で不要領域を発生させる(測定期間：1時間)
d. テーブルの不要行数とテーブルサイズを測定し続け、テーブル状態の推移を測定
b,cで発生された不要領域がautovacuumで回収されるかを評価
e. 「1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定」で見積もったautovacuum処理性能より、パラメータの設定値を決定し、再度a～eの処理を実行

今回の検証に用いた環境や検証手順に関しては 「検証環境・検証手順」 を参照してください。

4.6.1.4. 検証結果

1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定

autovacuumパラメータ値の変更により、次のようにautovacuumの処理時間が変化しました。 本検証で得られた結果より、任意テーブルでの不要領域発生速度を上回る、autovacuum処理性能を実現するためのパラメータ設定を算出可能です。

例えば「2. autovacuumのパラメータチューニングの効果を測定」にて定期的に発生する不要領域(312500行)を回収するためには、autovacuumのパラメータを以下の組み合わせにすることが望ましいと考えられます。

- autovacuum_vacuum_cost_limit : 600
- autovacuum_vacuum_cost_delay : 10
- autovacuum処理性能の見積もり結果：6281 (行/秒) → 376860 (行/分)

autovacuumにて不要領域発生速度を大幅に超える回収速度の設定を行った場合、autovacuumによるI/O負荷が高くなり、業務システムの性能に悪影響を与える可能性があるため、不要領域発生速度を大きく超えない値を設定し、「2. autovacuumのパラメータチューニングの効果を測定」にて、設定が妥当であるか否かを確認しました。


autovacuumパラメータチューニング結果

※下表は1秒間にautovacuumが処理できる平均行数、()内はデフォルト設定を1とした場合との性能比率


表 4.2 autovacuum_vacuum_cost_limit変更による処理性能比較
設定値 200 400 600 800 1000
cost_delay=20
1645
(1.00)
3016
(1.83)
4046
(2.46)
5051
(3.07)
6113
(3.72)
cost_delay=15
2213
(1.35)
3842
(2.34)
5152
(3.13)
5961
(3.62)
6856
(4.17)
cost_delay=10
3087
(1.88)
5092
(3.10)
6281
(3.82)
7347
(4.47)
8013
(4.87)
cost_delay=5
5183
(3.15)
7399
(4.50)
8588
(5.22)
9222
(5.61)
10054
(6.11)

2. autovacuumのパラメータチューニングの効果を測定

本検証では、「1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定」で得られた、autovacuumパラメータ値で不要領域の増加によるテーブル肥大化を抑止できることが確認できました。


更新頻度の高いテーブルでのautovacuum動作確認(チューニング前)
更新頻度の高いテーブルでのautovacuum動作確認(チューニング後)

4.6.1.5. 考察

本検証では、autovacuum_vacuum_cost_delayとautovacuum_vacuum_cost_limitを用いたautovacuumのパラメータ値の設計方法の明確化を目的とした検証を行い、次の結果が得られました。

  • 不要領域の発生速度に対しautovacuumのパラメータ設定値を適切に設計する方法
  • 上記で得られたパラメータ設定値を適用した場合、想定通りテーブル肥大化を抑止できること

本検証で検討したautovacuum処理性能を基にパラメータ値の設計方法は、有効であると考えます。

また、今回の検証ではインデックスが定義された列の値を更新しており、HOTが効かないパターンで大量の不要領域を発生させております。(インデックスが定義された列を更新しないUPDATE文では、HOTにより不要領域の発生が抑えられるため) 実際の業務システムにおいて、上記のようにインデックスが定義された列の値を大量に更新するテーブルについては今回と同様の検証を行い、テーブル肥大化を抑止するautovacuumパラメータの設計を実施することを推奨します。

しかしながら、今回チューニングを実施したパラメータ以外にもmaintenance_work_memを変更させた場合や、パラメータチューニングによるI/Oへの影響などの性能測定など他にも測定が必要な項目がございます。 また、実運用に即したパラメータチューニングを検討するのであれば、autovacuumの不要領域の回収速度を測定する際に、実運用に沿った負荷を与えた状態でスループットを評価するなど検証を考慮する必要がありますが、これらの測定につきましては、来年度以降を考えております。

4.6.1.6. 検証環境・検証手順

■ 検証環境


検証環境

表 4.3 環境情報
項目 説明
CPU
2.40GHz CPU x 2コア(4スレッド)
メモリ
8GB
ディスクサイズ
SSD 180GB
OSバージョン
CentOS 7.5 64bit
PostgreSQL
11.1
pgbench
PostgreSQL 11.1 付属

表 4.4 PostgreSQLの設定
パラメータ 設定値
listen_addresses
‘*’
max_connections
300
shared_buffers
2GB
effective_io_concurrency
200
max_wal_size
4GB
min_wal_size
2GB
checkpoint_completion_target
0.9
random_page_cost
1.1

表 4.5 autovacuumパラメータチューニングの測定項目
項番 測定項目 対象パラメータ 測定パターン
① autovacuum_vacuum_cost_limitを変更させた場合の処理時間の推移 autovacuum_vacuum_cost_limit {200, 400, 600, 800, 1000}
② autovacuum_vacuum_cost_delayを変更させた場合の処理時間の推移 autovacuum_vacuum_cost_delay {20, 10, 5}
③ パラメータを組み合わせて変更させた場合の処理時間の推移
autovacuum_vacuum_cost_limit
autovacuum_vacuum_cost_delay
{200, 400, 600, 800, 1000}

■ 検証手順(1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定)

以下の手順にて検証を行います。

pgbenchコマンドの初期化モード(スケールファクタ=100)にて10,000,000行のテーブルを作成します。

$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -i -s 100 <データベース名>

pgbenchのベンチマークにて更新対象となるカラムにインデックスを付与し、HOT機能の効果を受けないようにします。

$ psql -h <ホスト名> -p <ポート番号> -U <ユーザ名> -d <データベース名>
=# CREATE INDEX pgbench_accounts_filler_idx ON pgbench_accounts(filler);

ALTERコマンドにてautovacuumのログ出力、パラメータチューニングを実施し、autovacuumを停止させます。

=# ALTER TABLE pgbench_accounts SET (log_autovacuum_min_duration = 0);
=# ALTER TABLE pgbench_accounts SET (autovacuum_vacuum_cost_delay = <コスト遅延値>, autovacuum_vacuum_cost_limit = <コスト限界値>);
=# ALTER TABLE pgbench_accounts SET (autovacuum_enabled = false, toast.autovacuum_enabled = false);

そのテーブルに対し、UPDATEコマンドを実行することで25%の不要領域を発生させます。 ANALYZEコマンドを実施し、不要領域が発生していることを確認します。

=# UPDATE pgbench_accounts SET filler=repeat(md5(current_timestamp::text), 2) WHERE MOD(aid, 4) = 0;
=# ANALYZE pgbench_accounts;
=# SELECT n_tup_upd, n_tup_hot_upd, n_live_tup, n_dead_tup, last_autovacuum, autovacuum_count FROM pg_stat_user_tables WHERE relname = 'pgbench_accounts';

autovacuumを動作させ、任意の時間スリープ処理を行います。 スリープ処理が完了したら、autovacuumにより不要領域が回収されていることを確認します。

=# ALTER TABLE pgbench_accounts SET (autovacuum_enabled = true, toast.autovacuum_enabled = true);
=# SELECT pg_sleep(1800);
=# SELECT n_tup_upd, n_tup_hot_upd, n_live_tup, n_dead_tup, last_autovacuum, autovacuum_count FROM pg_stat_user_tables WHERE relname = 'pgbench_accounts';

PostgreSQLのログを確認し、autovacuumの処理時間を確認します。

(autovacuumログの出力例)
XXXX-XX-XX XX:XX:XX.XXX JST [XXXXX] LOG:  automatic vacuum of table "testdb.public.pgbench_accounts": index scans: 1
    pages: 0 removed, 204919 remain, 0 skipped due to pins, 0 skipped frozen
    tuples: 2500000 removed, 10000000 remain, 0 are dead but not yet removable, oldest xmin: 133064791
    buffer usage: 595395 hits, 211481 misses, 558034 dirtied
    avg read rate: 1.036 MB/s, avg write rate: 2.735 MB/s
    system usage: CPU: user: 48.15 s, system: 22.34 s, elapsed: 1594.11 s

■ 検証手順(2. autovacuumのパラメータチューニングの効果を測定)

以下の手順にて検証を行います。 まずは、「1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定」の結果からautovacuumのデフォルト値(autovacuum_vacuum_cost_limit=200, autovacuum_vacuum_cost_delay=20)での処理性能を以下の計算式で算出します。

不要領域 / autovacuum処理時間 = 2500000 / 1519.67 ≒ (1秒間あたり) 1645.10
(1分間の処理性能を算出)
1645.10 * 60 = 98706

デフォルト設定でのautovacuum処理性能では回収できない不要領域を定期的に発生させるために、1分間毎にテーブルの1/32をUPDATEすることで対応します。

テーブル行数 / 32 = 10000000 / 32 = 312500

pgbenchコマンドの初期化モード(スケールファクタ=100)にて10,000,000行のテーブルを作成します。

$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -i -s 100 <データベース名>

pgbenchのベンチマークにて更新対象となるカラムにインデックスを付与し、HOT機能の効果を受けないようにします。

$ psql -h <ホスト名> -p <ポート番号> -U <ユーザ名> -d <データベース名>
=# CREATE INDEX pgbench_accounts_filler_idx ON pgbench_accounts(filler);

ALTERコマンドにてautovacuumのログ出力、パラメータ設定させます。

=# ALTER TABLE pgbench_accounts SET (log_autovacuum_min_duration = 0);
=# ALTER TABLE pgbench_accounts SET (autovacuum_vacuum_cost_delay = 20, autovacuum_vacuum_cost_limit = 200);

そのテーブルに対し、UPDATEコマンドを実行することで25%の不要領域を発生させます。

=# UPDATE pgbench_accounts SET filler=repeat(md5(current_timestamp::text), 2) WHERE MOD(aid, 4) = 0;

その後、30秒毎にテーブルの状態を確認しながら、1分毎に更新処理を実施します。 その処理を1時間程度繰り返し実施します。

(30秒毎にテーブル状態を確認)
=# SELECT n_tup_upd, n_tup_hot_upd, n_live_tup, n_dead_tup, last_autovacuum, autovacuum_count FROM pg_stat_user_tables WHERE relname = 'pgbench_accounts';
=# SELECT pg_sleep(30);

(1分毎にテーブルを更新)
=# UPDATE pgbench_accounts SET filler=repeat(md5(current_timestamp::text), 2) WHERE MOD(aid, 32) = <カウンタ値>%32;

上記の検証にてテーブルの肥大化が確認できましたら、再度「1. autovacuumによる不要領域の回収速度を各パラメータの設定値ごとに測定」の結果より不要領域を回収できるようにautovacuum処理性能からパラメータチューニングを行い、同様の検証を行います。

(autovacuum_vacuum_cost_delay = 10, autovacuum_vacuum_cost_limit = 600 時のautovacuum処理性能)
不要領域 / autovacuum処理時間 = 2500000 / 397.98 ≒ (1秒間あたり) 6281.73
(1分間の処理性能を算出)
6281.73 * 60 = 376903.8

$ psql -h <ホスト名> -p <ポート番号> -U <ユーザ名> -d <データベース名>
=# ALTER TABLE pgbench_accounts SET (autovacuum_vacuum_cost_delay = 20, autovacuum_vacuum_cost_limit = 600);

(※再度不要領域の発生から検証を繰り返す)

4.6.2. pg_basebackup中の性能影響

4.6.2.1. 概要

■ pg_basebackup概要

PostgreSQLでは稼動中のデータベースクラスタの物理バックアップを取得するためのコマンドです。 pg_basebackupコマンドは一般的にPITR(Point In Time Recovery)のためのベースバックアップや、ストリーミングレプリケーションのスタンバイサーバ構築などに使用されます。

■ pg_basebackup利用においての課題

pg_basebackupコマンドにて物理バックアップを取得する際の負荷についての情報は、現状不足していると考えています。

■ 検証の目的

pg_basebackupコマンドによるバックアップ取得時にどの程度スループットの影響があるかを明確にすることを目的とします。

4.6.2.2. 検証内容

本検証では、以下の内容を実施しました。

  1. pgbenchによる平常時とpg_basebackup実行時でのトランザクション処理性能の測定
    pgbenchでクライアント数とスレッドワーカ数を変更させ、平常時とインデックス再作成時それぞれの条件でのトランザクション性能を測定します。
    pg_basebackupで作成するファイルは実際の運用を想定し、別サーバへの格納とします。

4.6.2.3. 検証方法

「1. pgbenchによる平常時とpg_basebackup実行時でのトランザクション処理性能の測定」は次のように実施

a. 1500万件のデータが格納されたテーブルを作成、
b. テーブルに対しpgbenchによるトランザクション試験を実行し、TPS値(秒間あたりのトランザクション処理件数)を測定
c. クライアントからpg_basebackupコマンドをバックグラウンドで実行したまま、bと同様の処理を実行

今回の検証に用いた環境や検証手順に関しては 「検証環境・検証手順」 を参照してください。

4.6.2.4. 検証結果

pg_basebackup実行中の性能影響は平常時の13～18%程度低下するとの測定結果となりました。


pg_basebackup性能影響(更新+参照)

今回性能差の大きかった条件(クライアント数=32)で取得したsarの情報を基に検証中のディスクI/Oを調査しました。 平常時と比べて読み込むセクタ数(rd_sec/s)は増加していますが、avgqu-sz(平均待ち行列長)やawait(レスポンスタイム)に違いがないことから、pg_basebackup実行中にディスクI/Oでボトルネックは発生していないと推測致します。

(平常時のディスクI/O)
     DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
dev253-2    654.00  15008.00  13744.00     43.96      5.59      8.02      1.23     80.20
dev253-2    616.00  13312.00  13360.00     43.30      5.72      9.79      1.34     82.50
dev253-2    600.00  13808.00  12496.00     43.84      5.54      9.19      1.37     82.10
dev253-2    579.00  12176.00  19552.00     54.80      5.87      9.80      1.48     85.60
dev253-2    702.00  14352.00  15216.00     42.12      6.20      9.14      1.25     87.70
dev253-2    637.00  14424.00  13696.00     44.14      4.50      7.01      1.16     74.10
dev253-2    437.00  10096.00   9872.00     45.69      7.15     16.19      2.05     89.70
dev253-2    522.00  11456.00  10624.00     42.30      7.73     14.96      1.74     90.70
dev253-2    681.00  14608.00  15088.00     43.61      5.41      7.88      1.23     83.60
dev253-2    634.00  15888.00  12640.00     45.00      7.48     11.73      1.36     86.00
dev253-2    644.00  12752.00  14320.00     42.04      5.36      8.08      1.27     82.10

(pg_basebackup時のディスクI/O)
     DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
dev253-2    741.00  50544.00  11424.00     83.63      6.90      8.98      1.22     90.10
dev253-2    853.00  71088.00  12640.00     98.16      5.17      6.28      0.95     81.30
dev253-2    811.00  63424.00  11904.00     92.88      5.12      6.19      0.98     79.10
dev253-2    811.00  63104.00  12752.00     93.53      5.14      6.40      1.00     81.00
dev253-2    733.00  56336.00  10896.00     91.72      6.49      8.62      1.16     85.30
dev253-2    797.00  57088.00  16328.00     92.12      5.22      6.71      1.06     84.70
dev253-2    788.00  60336.00  11776.00     91.51      4.95      6.20      1.06     83.60
dev253-2    764.00  63568.00  11392.00     98.12      5.51      7.28      1.09     83.20
dev253-2    796.00  61072.00  12128.00     91.96      4.91      6.09      1.01     80.00
dev253-2    704.00  51456.00  11232.00     89.05      6.49      9.17      1.19     84.10
dev253-2    776.00  57120.00  12096.00     89.20      5.12      6.54      1.06     82.20

同様にsarの情報のCPU使用率からは、pg_basebackup中には%userの値が平均3%程度低下していることが確認できます。 %userはPostgreSQLの処理に影響しますので、今回のpg_basebackup実行中の性能低下は%userの低下によるものだと推測致します。


pg_basebackup性能影響(更新+参照) - CPU負荷比較(クライアント数=4)
pg_basebackup性能影響(更新+参照) - CPU負荷比較(クライアント数=32)

4.6.2.5. 考察

本検証では、pg_basebackupコマンドによるバックアップ取得時にどの程度スループットの影響調査を目的とした検証を行い、次の結果が得られました。

  • pg_basebackup実行中は平常時と比べ、13～18%程の性能低下が見られた

今回の性能影響の原因について調査を行ったところ、次のことが確認できました。

  • pg_basebackup実行中は、ディスクI/Oへの読み込みは増加しているが、平常時と同様にOSが十分に捌けており、ディスクI/Oでボトルネックは発生していない
  • pg_basebackup実行中に%userの低下が見られ、その分トランザクションの処理のCPU利用時間が減少

性能影響の直接的な原因である%userの低下はカーネルにて実行している処理の時間が長くなっていることが起因していると考えられます。(%sysが上昇したことから推測) カーネルの処理が長くなることでユーザプログラム(トランザクション処理)にCPUを利用できていない時間が発生していると推測しておりますが、今後検討が必要と考えています。

%sysが上昇する要因として、以下の事象が考えられます。

  • OS機能であるTHP(Transparent Huge Page)に関連したdefrag(compaction alloc)処理の影響
  • pg_basebackupでの大量データの読み込みによるカーネル処理の増加による影響

本検証では、pg_basebackup実行中での性能影響が確認されましたが、pg_basebackupにはサーバから転送されるデータの最大転送速度(-rオプション)を設定することが可能です。 pg_basebackupによる性能影響を抑止したい場合はこちらのオプションを検討することを推奨致します。

4.6.2.6. 検証環境・検証手順

■ 検証環境


検証環境

表 4.6 PostgreSQLの設定
パラメータ 設定値
listen_addresses
‘*’
max_connections
300
shared_buffers
2GB
effective_io_concurrency
200
max_wal_size
4GB
min_wal_size
2GB
checkpoint_completion_target
0.9
random_page_cost
1.1

表 4.7 ベンチマーク条件
パラメータ 設定値
クライアント数
{1, 2, 4, 8, 16, 32, 64, 128, 256}
ワーカスレッド数
{1, 1, 2, 4, 8, 16, 32, 64, 128} ※クライアント数の半分

■ 検証手順

pgbenchコマンドの初期化モード(スケールファクタ=1500)にて150,000,000行のテーブルを作成します。

$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -i -s 1500 <データベース名>

クライアントサーバからpg_basebackupを動作させていない状態でpgbenchコマンド(デフォルトの組み込みトランザクションスクリプト)を実行します。 ベンチマーク条件に基づき、クライアント数とワーカスレッド数を変更させていき、それぞれの条件でのTPS値を測定します。

$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -c <クライアント数> -j <ワーカスレッド数> -T <トランザクション実行時間> -r <データベース名>

次に、pg_basebackupを動作させた状態でpgbenchコマンド(デフォルトの組み込みトランザクションスクリプト)を実行し、TPS値を測定します。 クライアント数に応じたTPS値を3回取得し、その平均値を算出します。

$ rm -rf /tmp/test/*
$ pg_basebackup -h <ホスト名> -p <ポート番号> -U <ユーザ名> -D /tmp/test -Ft -Xs -c fast -z &
$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -c <クライアント数> -j <ワーカスレッド数> -T <トランザクション実行時間> -r <データベース名>

4.6.3. インデックス再作成中の性能影響

4.6.3.1. 概要

■ 長期間運用していく上でのB-treeインデックスの課題

B-treeインデックス(以降、インデックス)に格納されるデータはページと呼ばれる領域(デフォルト:8192B)に格納されます。 ページ内のほとんどのデータが削除された場合でも、一部のデータがページに残る場合は、ページは割り当てられたまま残ります。 ページ内のほとんどのデータを削除するような操作が繰り替えし実行されると、1ページに格納されるデータ数が少なくなり、インデックスが肥大化した状態になります。 インデックスが肥大化した場合、無駄なディスク領域が必要となるだけではなく、性能トラブルを引き起こす要因にもなります。

■ 課題についての対処方法

このような場合、インデックスの再作成が必要となりますが、インデックスの再作成の方法の一つである「REINDEX」は、処理中に該当インデックスに排他ロックを取得しますので、インデックスを利用した参照処理とテーブルの更新処理はロック待ちになります。 「REINDEX」を実行する他にインデックスの再作成方法として、「CREATE INDEX CONCURRENTLY」にて新しいインデックスを作成した後に古いインデックスを削除する方法があります。 一般的にメンテンナンス時間が設けられる場合であれば、「REINDEX」を実行することは可能ですが、システムが停止できないような場合であれば排他ロックを獲得せずにインデックスを作成できる「CREATE INDEX CONCURRENTLY」が選択されると考えられます。

■ 検証の目的

「CREATE INDEX CONCURRENTLY」は運用中に実行されることが多い処理であることから、性能への影響についての知見を得る必要があると考えました。 そこで本検証では、インデックス再作成実行中の性能への影響調査を行うことを目的とします。

4.6.3.2. 検証内容

本検証では、以下の内容を実施しました。

  1. pgbenchによる平常時とインデックス再作成時でのトランザクション処理性能の測定
    pgbenchでクライアント数とスレッドワーカ数を変更させ、平常時とインデックス再作成時それぞれの条件でのトランザクション性能を測定します。

4.6.3.3. 検証方法

「1. pgbenchによる平常時とインデックス再作成時でのトランザクション処理性能の測定」は次のように実施

a. 1000万件のデータが格納されたテーブルを作成
b. pgbenchのTPC-Bに基づいたシナリオ内で更新対象となっているカラムにインデックスを作成
c. テーブルに対しpgbenchによるトランザクション試験を実行し、TPS値(秒間あたりのトランザクション処理件数)を測定
d. インデックス再作成をバックグラウンドで実行したまま、cと同様の処理を実行

今回の検証に用いた環境や検証手順に関しては 「検証環境・検証手順」 を参照してください。

4.6.3.4. 検証結果

インデックス再作成中の性能影響は平常時と比べ15～20%程度低下するとの測定結果となりました。(クライアント数が少ない場合は、影響大)


インデックス再作成中の性能影響(更新+参照)

今回性能差の大きかった条件(クライアント数=32)で取得したsarの情報を基に検証中のディスクI/Oを調査しました。 平常時と比べavgqu-sz(平均待ち行列長)、await(レスポンスタイム)が非常に大きくなっていることが確認できます。 また、値が大きくなった時間帯ではwr_sec/s(秒間あたりのI/Oの書き込み回数)も多くなっていることから、I/Oのリクエスト数が多くなりすぎて処理が捌き切れていないことが推測できます。

(平常時のディスクI/O)
     DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
dev253-2    727.00  19184.00  11920.00     42.78      7.15      9.69      1.23     89.50
dev253-2    739.00  17584.00  12336.00     40.49      7.40     10.03      1.24     91.30
dev253-2    704.00  16848.00  12608.00     41.84      4.61      6.23      1.09     76.60
dev253-2    661.00  15744.00  12112.00     42.14      5.58      8.77      1.25     82.70
dev253-2    801.00  20704.00  13936.00     43.25      6.49      8.15      1.07     85.90
dev253-2    838.00  21616.00  14272.00     42.83      6.71      7.96      1.01     85.00
dev253-2    710.00  16512.00  13728.00     42.59      6.91      9.74      1.20     85.40
dev253-2    685.00  16544.00  11840.00     41.44      5.78      8.33      1.24     84.70
dev253-2    612.00  14000.00  11008.00     40.86      8.32     13.57      1.49     91.30
dev253-2    703.00  18080.00  12272.00     43.17      7.18     10.29      1.20     84.10
dev253-2    714.00  17456.00  12176.00     41.50      6.20      8.45      1.19     85.10

(インデックス再作成時のディスクI/O)
     DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
dev253-2     64.00      0.00  65536.00   1024.00    176.68   2075.91     15.61     99.90
dev253-2    160.00      0.00 163840.00   1024.00    175.40   1361.49      6.26    100.10
dev253-2    128.00      0.00  98656.00    770.75    183.82    786.90      7.81    100.00
dev253-2    281.00    688.00 131408.00    470.09    244.26   1068.52      3.56    100.00
dev253-2     96.00      0.00  98304.00   1024.00    278.52   1276.47     10.42    100.00
dev253-2     89.00      0.00  88866.00    998.49    276.28   1643.65     11.24    100.00
dev253-2     20.00     48.00   1891.00     96.95    181.32  31587.00     49.80     99.60
dev253-2    610.00   4320.00  89840.00    154.36     12.02     19.56      1.44     87.60
dev253-2    775.00   5968.00  87040.00    120.01     10.32     13.34      1.15     89.30
dev253-2    972.00   6560.00 105296.00    115.08     68.44     64.57      0.98     95.00
dev253-2    784.00   4336.00  92848.00    123.96     38.38     56.15      1.22     96.00

同様にsarの情報のCPU使用率からも、インデックス再作成中は%iowaitの値が平均10%程度増加し、%userも平常時と比べ、平均5%程度の低下がみられることが確認できます。 CPU使用率からも%iowaitが高くなっていることから、ディスクI/Oでボトルネックが発生している可能性があることが推測できます。


インデックス再作成中の性能影響(更新+参照) - CPU負荷比較(クライアント数=4)
インデックス再作成中の性能影響(更新+参照) - CPU負荷比較(クライアント数=32)

4.6.3.5. 考察

本検証では、インデックス再作成実行中の性能への影響調査を目的とした検証を行い、次の結果が得られました。

  • インデックス再作成実行中は平常時と比べ、15～20%程の性能低下が見られた

今回の性能影響の原因について調査を行ったところ、次のことが確認できました。

  • インデックス再作成実行中はI/Oへのリクエスト数が増加することから、ディスクI/Oがボトルネックになる可能性が高い
  • ディスクI/Oがボトルネックになってしまうことで、同時間帯に実行されている他の処理への性能影響も大きいと判断する

「CREATE INDEX CONCURRENTLY」にて行うインデックスの再作成は更新処理を阻害するようなロックを取得しないため、業務中での実行も可能ですが、性能への影響を考慮した場合は、メンテナンス時間や夜間など、負荷が少ない時間帯での実行を推奨致します。

4.6.3.6. 検証環境・検証手順

■ 検証環境


検証環境

表 4.8 環境情報
項目 説明
CPU
2.40GHz CPU x 2コア(4スレッド)
メモリ
8GB
ディスクサイズ
SSD 180GB
OSバージョン
CentOS 7.5 64bit
PostgreSQL
11.1
pgbench
PostgreSQL 11.1 付属

表 4.9 PostgreSQLの設定
パラメータ 設定値
listen_addresses
‘*’
max_connections
300
shared_buffers
2GB
effective_io_concurrency
200
max_wal_size
4GB
min_wal_size
2GB
checkpoint_completion_target
0.9
random_page_cost
1.1

表 4.10 ベンチマーク条件
パラメータ 設定値
クライアント数
{1, 2, 4, 8, 16, 32, 64, 128, 256}
ワーカスレッド数
{1, 1, 2, 4, 8, 16, 32, 64, 128} ※クライアント数の半分

■ 検証手順

pgbenchコマンドの初期化モード(スケールファクタ=1000)にて100,000,000行のテーブルを作成します。

$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -i -s 1000 <データベース名>

psqlコマンドにてpgbench_accountsテーブルの更新対象となっているカラム(abalance)にインデックスを作成します。

$ psql -h <ホスト名> -p <ポート番号> -U <ユーザ名> -d <データベース名> -c "CREATE INDEX pgbench_accounts_abalance_idx ON pgbench_accounts(abalance)"

クライアントサーバからインデックスの再作成「CREATE INDEX CONCURRENTLY」を実行させていない状態でpgbenchコマンド(デフォルトの組み込みトランザクションスクリプト)を実行します。 ベンチマーク条件に基づき、クライアント数とワーカスレッド数を変更させていき、それぞれの条件でのTPS値を測定します。

$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -c <クライアント数> -j <ワーカスレッド数> -T <トランザクション実行時間> -r <データベース名>

次に、インデックスの再作成「CREATE INDEX CONCURRENTLY」を実行させた状態でpgbenchコマンド(デフォルトの組み込みトランザクションスクリプト)を実行し、TPS値を測定します。 クライアント数に応じたTPS値を3回取得し、その平均値を算出します。

$ psql -h <ホスト名> -p <ポート番号> -U <ユーザ名> -d <データベース名> -c "DROP INDEX pgbench_accounts_abalance_idx_new"
$ psql -h <ホスト名> -p <ポート番号> -U <ユーザ名> -d <データベース名> -c "CREATE INDEX CONCURRENTLY pgbench_accounts_abalance_idx_new ON pgbench_accounts(abalance)" &
$ pgbench -h <ホスト名> -p <ポート番号> -U <ユーザ名> -c <クライアント数> -j <ワーカスレッド数> -T <トランザクション実行時間> -r <データベース名>

5. 性能状態を把握するための監視

DBサーバの性能状態を正確に把握するためには、性能に関連する情報(以降、性能情報)を定期的に取得し、蓄積しておく必要があります。
性能トラブルが発生した場合には、蓄積した性能情報を元にボトルネック(問題を発生させる要素)を特定し、
ボトルネックが発生した原因について詳細に分析します。そして、分析結果を元に性能改善の施策を検討・実施する必要があります。

PostgreSQLが稼働するDBサーバの性能情報を蓄積し、ボトルネックの特定や分析を支援する機能を提供するソフトウェアは数多く存在し、「Monitoring - PostgreSQL wiki」 [1] に整理されています。
また、2015年度のWG3の活動にて、性能監視ツールに求められる要件を整理し、pg_statsinfo(およびpg_stats_reporter)やpg_monzの調査を実施しております。
調査結果の詳細は、「2015年度WG3活動報告書（データベースツール編）」 [2] や「付録_性能監視ツール」 [3] [4] をご参照下さい。

[1]Monitoring/ja - PostgreSQL wiki - 2 外部ツールプロジェクト
[2]2015 年度 WG3 活動報告書 - データベースツール編
[3]付録_性能監視ツール1
[4]付録_性能監視ツール2

性能トラブル発生時のボトルネックの特定および分析は、一般的には以下のような手法を用います。

表 5.1 性能情報の分析手法
項番 概要 説明 備考
1 過去情報との比較 トラブル発生時の情報と、過去の正常時の値を比較し、差分を確認することでボトルネックを絞り込む手法 性能情報を定期的に取得し、正常な状態(ベースライン)の性能情報を保持する必要がある
2 ドリルダウン手法 広い視点で情報を確認し、性能トラブルと関係がないと考えられる情報を捨て、関係が疑われる領域の情報を深堀していく手法 サーバの処理が全体的に遅延した場合に用いることが多い
3 処理時間に着目した分析 特定の処理に着目し、遅延した原因の詳細を深堀していく手法 特定の処理のみが遅延した場合に用いることが多い

ここでは、システム管理者などが性能トラブル発生時のボトルネック特定および分析する際に一助となる情報を提供することを目的し、
性能情報を分析するための観点(取得すべき情報)を整理しております。

5.1. 調査検証時に利用した環境

本章を記載するにあたり、利用した環境の情報は以下の通りです。

表 5.2 利用した環境情報
項目 説明 備考
OSバージョン CentOS Linux release 7.4.1708 (Core)
-
sysstatバージョン 10.1.5-12.el7 sarコマンド、iostatコマンドを利用するためにインストール
procpsバージョン 3.3.10-16.el7 topコマンドを利用するためにインストール
PostgreSQLバージョン 10.2
-
構成 シングル構成(1台)
-

5.2. 性能情報の種別

OSのツール(sarコマンドやtopコマンド)やPosgresSQLは、コマンドラインやテーブルやビューなどを通して収集した性能情報を提供しております。
性能情報には以下種別の情報が存在します。
性能情報を正確に分析するためには、どの種別の性能情報なのかを事前に把握しておく必要があります。

表 5.3 性能情報の種別
項目 種別 説明 備考
1 累計値 ある時刻から収集された値の合計値
例えば、トランザクションのコミット数やロールバック数など。
単位時間毎の変化量を把握したい場合は、定期的に取得し、差分を確認する必要がある。
2 瞬間値 ある時点での状況や状態を示す値 例えば、トランザクション開始からの経過時間、現在実行中のSQL文など。
3 瞬間値(平均値) 測定開始した時間から、測定終了までの値 例えば、5秒間のCPU使用率の平均値など

5.3. 一定時間内に実行された処理の結果

性能トラブルを分析するには、システム管理者は”正常な状態の時に、一定時間内にどの程度処理ができているか”、
“どの程度処理に時間が掛かっているか”を把握しておく必要があります。
一定時間内に実行された処理の結果を把握しておくことで、性能トラブルが発生した時に以下の観点で調査を行うことができます。
・トランザクション数が増加することで負荷が増加し、性能トラブルに至っていないか
・処理遅延により実行されるトランザクション数が減少し、性能トラブルに至っていないか
このように正常時との比較を行うことで、性能トラブルを引き起こしている原因の手がかりを調査していくことになります。

表 5.4 一定時間内に実行された処理の結果
項番 性能情報 種別 概要
1 トランザクション数 累計値
トランザクションコミット数/ロールバック数
2 SQL処理 累計値
SQLの統計情報
3 遅延SQL
-
遅延SQL

5.3.1. トランザクション数

5.3.1.1. トランザクションコミット数/ロールバック数

pg_stat_databaseビュー [1] では、トランザクションコミット数とロールバック数の累計値が収集されています。
以下のようなSQLを用いることで、データベース毎に情報を取得することができます。
(サンプルSQL)
=#
SELECT
    datname,
    xact_commit,
    xact_rollback
FROM
    pg_stat_database;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]-+----------
datname       | postgres
xact_commit   | 22665
xact_rollback | 0
-[ RECORD 2 ]-+----------
datname       | testdb
xact_commit   | 73986
xact_rollback | 23
-[ RECORD 3 ]-+----------
datname       | template1
xact_commit   | 0
xact_rollback | 0
-[ RECORD 4 ]-+----------
datname       | template0
xact_commit   | 0
xact_rollback | 0

出力されるカラム情報は以下になります。

datname : データベース名
xact_commit : トランザクションコミット数
xact_rollback : トランザクションロールバック数

・確認観点

トランザクション数が低下している場合
以下のような事象が考えられます。
1. 実行されているトランザクション数が少なくなっている。(夜間帯などでトランザクション実行数が少ない)
2. 何らかのボトルネックが原因でPostgreSQLでのトランザクション処理数が低下している。(性能トラブル)

・参考情報

[1]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_stat_databaseビュー

5.3.2. SQL処理

5.3.2.1. SQLの統計情報

pg_stat_statementsモジュール [2] では、SQLの実行回数や総実行時間などに関する統計情報を取得しています。
以下のようなSQLを用いることで、SQLの統計情報を取得することができます。
実行時間が掛かっているSQL(=遅延SQL)や性能影響の大きいSQLを検知することができます。
(サンプルSQL)
=#
SELECT
    query,
    calls,
    total_time,
    rows,
    100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent
FROM
    pg_stat_statements
ORDER BY
    total_time DESC LIMIT 5;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---------------------------------------------------------------------------------------------------------
query       | EXPLAIN ANALYZE SELECT * FROM pgbench_branches b JOIN pgbench_accounts a ON b.bid = a.bid ORDER BY a.aid
calls       | 4
total_time  | 14268.609267
rows        | 0
hit_percent | 91.0248161764705882
-[ RECORD 2 ]---------------------------------------------------------------------------------------------------------
query       | SELECT * FROM pgbench_branches b JOIN pgbench_accounts a ON b.bid = a.bid ORDER BY a.aid
calls       | 4
total_time  | 1390.60727
rows        | 400000
hit_percent | 100.0000000000000000

出力されるカラム情報は以下になります。

query : SQL文の文字列(track_activity_query_size バイトまで)
calls : 実行回数
total_time : SQLの総実行時間
rows : SQL文によって取得された、あるいは影響を受けた行の総数
hit_percent : キャッシュヒット率

・確認観点

pg_stat_statment [2] の利用で、データベースへの性能影響が大きい以下のSQLを抽出することが可能です
1. SQLの総実行時間が長いSQL
2. 一回あたりの実行時間が長いSQL(total_time÷calls)

・参考情報

[2](1, 2) PostgreSQL 10.0文書 - 付録F 追加で提供されるモジュール F.30. pg_stat_statements

5.3.3. 遅延SQL

5.3.3.1. 遅延SQL

auto_explainモジュール [3] は、指定した時間よりも遅延したSQLの実行計画を自動的にログに出力します。
遅延SQLの特定や遅延時に選択された実行計画を確認する際に効果的な情報です。
※ log_min_duration_statementパラメータ [4] に任意の時間を指定することで、指定した時間より遅延したSQL文をログに出力することも可能です。
監視対象ログファイル: PostgreSQLログ
監視対象文字列：LOG、duration

LOG:  duration: 252.673 ms  plan:
        Query Text: SELECT * FROM pgbench_branches b JOIN pgbench_accounts a ON b.bid = a.bid ORDER BY a.aid;
        Nested Loop  (cost=0.29..6121.39 rows=100060 width=465)
          Join Filter: (b.bid = a.bid)
          ->  Index Scan using pgbench_accounts_pkey on pgbench_accounts a  (cost=0.29..4619.47 rows=100060 width=97)
          ->  Materialize  (cost=0.00..1.01 rows=1 width=364)
                ->  Seq Scan on pgbench_branches b  (cost=0.00..1.01 rows=1 width=364)

cost : コスト(シーケンシャルI/Oで1ページを読み込むコストを1.0とした際の相対値)
rows : 推定された行数

・確認観点

指定した時間よりも処理が遅延しているSQLを検知
該当のSQLが遅延している事を示します。
遅延SQLを特定した後、詳細な調査が必要な場合には、
EXPLAIN ANALYZE [遅延SQL] を実行することで、SQL実行時の各計画ノード(スキャンや結合などの内部処理)にかかった時間を取得することが可能です。
上記結果を元に問題箇所の特定を行います。

・参考情報

[3]PostgreSQL 10.0文書 - 付録F 追加で提供されるモジュール F.4. auto_explain
[4]PostgreSQL 10.0文書 - 第19章 サーバの設定 19.8. エラー報告とログ取得 log_min_duration_statementパラメータ

5.4. 任意の時間帯の処理実行状況

性能トラブル時にボトルネックを探すため、”このシステムでどういった処理が実行されているか”を把握する必要があります。
任意の時間帯の処理実行状況を把握しておくことで、性能トラブルが発生した時に以下の観点で調査を行うことができます。
・性能トラブル発生時の処理は、正常動作時と比べ違いがあるか
・性能トラブル発生時に実行中のプロセスで、ロック待ちが発生していないか
・正常動作時に確認されていない処理が行われていないか
・autovacuumなどのメンテナンス処理は正常に実行されているか
このような判断を行った上で、性能トラブルを引き起こしている原因やボトルネックになっている事象を調査していきます。

表 5.5 任意の時間帯の処理実行状況
項番 性能情報 種別 概要
1 実行中のトランザクション 瞬間値
トランザクション確認
2 実行中のautovacuum処理 瞬間値
VACUUM進捗状況

5.4.1. 実行中のトランザクション

5.4.1.1. トランザクション確認

pg_stat_activityビュー [1] では、プロセスの状態とSQLの開始時間が収集されています。
以下のようなSQLを用いることで、実行中のSQL情報を取得することができます。
(サンプルSQL)
=#
SELECT
    pid,
    wait_event_type,
    wait_event,
    state,
    (current_timestamp - xact_start)::interval(3) AS duration,
    query
FROM
    pg_stat_activity
WHERE
    pid <> pg_backend_pid()
ORDER BY
    duration DESC;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---+------------------------------------------------------
pid             | 1447
wait_event_type | Activity
wait_event      | LogicalLauncherMain
state           |
duration        |
query           |
-[ RECORD 2 ]---+------------------------------------------------------
pid             | 1445
wait_event_type | Activity
wait_event      | AutoVacuumMain
state           |
duration        |
query           |
-[ RECORD 3 ]---+------------------------------------------------------
pid             | 1443
wait_event_type | Activity
wait_event      | BgWriterHibernate
state           |
duration        |
query           |
-[ RECORD 4 ]---+------------------------------------------------------
pid             | 1442
wait_event_type | Activity
wait_event      | CheckpointerMain
state           |
duration        |
query           |
-[ RECORD 5 ]---+------------------------------------------------------
pid             | 1444
wait_event_type | Activity
wait_event      | WalWriterMain
state           |
duration        |
query           |
-[ RECORD 6 ]---+------------------------------------------------------
pid             | 443
wait_event_type | Client
wait_event      | ClientRead
state           | idle in transaction
duration        | 00:00:52.961
query           | LOCK TABLE pgbench_accounts IN ACCESS EXCLUSIVE MODE;

出力されるカラム情報は以下になります。

pid : バックエンドのpid(postgresプロセスのpid)
wait_event_type : バックエンドが待機しているイベントの型
wait_event : 待機イベント名
duration : トランザクション開始からの経過時間
state : バックエンドの状態
query : 直近のSQL

・確認観点

長時間実行されているトランザクションが存在する場合
1. トランザクション内のSQLが完了しない(ロック待ちやハードウェアの割り当て待ちなど)
2. アプリケーションのコミット処理の漏れなどが原因でロングトランザクション化している。
ロングトランザクションは、autovacuumによる不要領域の回収などを妨げる等の問題を発生させるため、
ロングトランザクションを検知した場合は発生させないように対処が必要です。

・参考情報

[1]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_stat_activityビュー

5.4.2. 実行中のautovacuum処理

5.4.2.1. VACUUM進捗状況

pg_stat_progress_vacuumビュー [2] では、現在実行中のVACUUMに関する情報が収集されています。
以下のようなSQLを用いることで、実行中のVACUUM処理の状態を取得することができます。
ただし、VACUUM FULLの情報はサポートされておりません。
(サンプルSQL)
SELECT
    v.pid AS pid,
    v.datname AS datname,
    c.relname AS relname,
    v.phase AS phase,
    v.heap_blks_total AS heap_blks_total,
    v.heap_blks_scanned AS heap_blks_scanned,
    v.heap_blks_vacuumed AS heap_blks_vacuumed,
    v.index_vacuum_count AS index_vacuum_count,
    v.max_dead_tuples AS max_dead_tuples,
    v.num_dead_tuples AS num_dead_tuples
FROM
    pg_stat_progress_vacuum AS v
JOIN
    pg_class AS c
    ON v.relid = c.relfilenode;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]------+--------------
pid                | 24477
datname            | testdb
relname            | test
phase              | scanning heap
heap_blks_total    | 2655
heap_blks_scanned  | 141
heap_blks_vacuumed | 0
index_vacuum_count | 0
max_dead_tuples    | 772605
num_dead_tuples    | 32073

出力されるカラム情報は以下になります。

pid：バックエンドのプロセスID
datname：バックエンドが接続されているデータベース名
relname：バキューム処理が行われているテーブル名
phase：現在のバキュームの処理フェーズ
heap_blks_total：テーブルのヒープブロックの総数
heap_blks_scanned：スキャンされたヒープブロックの数
heap_blks_vacuumed：バキューム処理されたヒープブロックの数
index_vacuum_count：完了したインデックスバキュームサイクルの数
max_dead_tuples：インデックスバキュームサイクルの実行に必要となる前に格納することが出来る、maintenance_work_memに基づいた無効なタプルの数
num_dead_tuples：最後のインデックスバキュームサイクルから収集された無効タプルの数

・確認観点

VACUUM(autovacuum)が長時間終了しない場合
1. テーブルのサイズが大きく処理に時間がかかっている可能性があるため、VACUUM(autovacuum)のパラメータを検討する必要がある。
2. VACUUMが停止している場合は、VACUUM処理を阻害する要因が存在しないかを確認する。
例えば、カーソルが閉じられていないトランザクションはVACUUMの処理を阻害することがあります。
上記のトランザクションがロングトランザクション化しないように対処が必要です。

・参考情報

[2]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.4. 進捗状況のレポート pg_stat_progress_vacuumビュー

5.5. リソースの利用状況

性能トラブルを分析する際に、”正常時のHWリソース(CPUやメモリ、ディスク、ネットワークなど)の利用状況”を把握する必要があります。
正常時のHWリソースの利用状況を把握することで、性能トラブル時に以下の観点で調査を行うことができます。
・性能トラブル発生時のリソース使用状況は、正常な状態と比べ違いがあるか
・リソース利用に違いがある場合は、多くのリソースを使用するプロセスは存在するか
特定のプロセスが多くのリソースを使用している場合は該当プロセスが実行した処理を確認する必要があります。
(プロセスが実行した処理については「 任意の時間帯の処理実行状況 」を参照して下さい。)

表 5.6 リソースの利用状況
項番 性能情報 種別 概要
1 CPU利用率 瞬間値(平均値)
CPU利用率
2 メモリ状況 瞬間値(平均値)
メモリ状況
3 スワップ発生状況
瞬間値(平均値)
スワップ発生状況
4 ネットワーク使用状況
瞬間値(平均値)
ネットワーク使用状況
5 プロセスのリソース使用状況
瞬間値
プロセスのリソース使用状況

5.5.1. CPU利用率

sarコマンド [2] でシステムの統計情報を取得します。
-uオプションでCPU情報を表示させ、こちらを監視します。
# sar -u 5

一定間隔で結果が出力されます。

Linux 3.10.0-693.17.1.el7.x86_64 (localhost.localdomain)     2018年02月23日  _x86_64_        (1 CPU)

13時23分18秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
13時23分23秒     all      0.64      0.00      0.64     98.73      0.00      0.00
13時23分28秒     all      0.41      0.00      0.41     99.18      0.00      0.00
13時23分33秒     all      0.21      0.00      0.21     99.59      0.00      0.00
13時23分38秒     all      0.21      0.00      0.42     99.38      0.00      0.00

出力される情報は以下になります。

%user : ユーザプロセスによるCPU使用率
%nice : 実行優先度を変更した(niceコマンド)ユーザプロセスによるCPU使用率
%system : システムプロセスによるCPU使用率
%iowait : ディスクI/O要求がある間のCPUが、アイドル状態である時間の%表示
%steal : 仮想プロセッサを実行している間、強制的に待たされている時間の%表示
%idle : CPUがアイドル状態で、ディスクI/O要求がない状態の時間の%表示

・確認観点

%user+%niceが高い
OS上で稼働するユーザプロセス(PostgreSQL含む)の処理でCPU負荷が高いことを示しています。
topコマンドなどでCPU負荷の高いプロセスを特定し、実行している処理に問題がないかを確認します。

%systemが高い
カーネル処理でCPU負荷が高いことを示しています。
ユーザプロセスから実行したシステムコール(カーネルが処理)で負荷が高くになっている場合もあります。
また、DBサーバで大容量メモリを使用している場合は、
THP(Transparent Huge Page)に関連したdefrag(compaction alloc)処理による性能トラブル [1] がよく知られておりますので、注意して下さい。

%iowaitが高い
ディスクに対するI/O処理が競合し、待ちが発生していることを示しています。
ユーザプロセスが実行する処理の中で不要なディスクアクセスが発生し、ボトルネックになっていないかを確認します。

・参考情報

[1]THP(Transparent Huge Page)に関連したdefrag(compaction alloc)処理による性能トラブル
[2](1, 2, 3, 4, 5) sar manual page

5.5.2. メモリ状況

sarコマンド [2] でシステムの統計情報を取得します。
-rオプションでメモリ情報を表示させ、こちらを監視します。
# sar -r 5

一定間隔で結果が出力されます。

Linux 3.10.0-693.17.1.el7.x86_64 (localhost.localdomain)     2018年02月23日  _x86_64_        (1 CPU)

13時25分24秒 kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit  kbactive   kbinact   kbdirty
13時25分29秒    392572    624632     61.41         0    480112    618340     29.93    251696    255408       956
13時25分34秒    392324    624880     61.43         0    480504    618340     29.93    251932    255568       964
13時25分39秒    391952    625252     61.47         0    480896    618340     29.93    252156    255736       980
13時25分44秒    391580    625624     61.50         0    481228    618340     29.93    252364    255808       988

出力される情報は以下になります。

kbmemfree : メモリ空き容量(KB)
kbmemused : メモリ使用量(KB)
%memused : メモリ使用率
kbbuffers : カーネルによるバッファとしての使用量(KB)
kbcached : カーネルによるキャッシュとしての使用量(KB)
kbcommit : 現在の負荷量を処理するにあたり必要なメモリ量(KB)
%commit : 現在の負荷量を処理するにあたり必要な使用率
kbactive : アクティブなメモリの量(KB)
kbinact : アクティブでないメモリの量(KB)
kbdirty : ディスクに書きもどされるのを待っているメモリの量(KB)

・確認観点

kbmemused - (kbbuffers + kbcached) が徐々に増えている
メモリ使用量からページキャッシュ等を引いた実質のメモリ使用量(目安)を示しています。
この値が徐々に増加しているのであれば、使用するメモリ量が増加しています。
(単調に増加するパターンや増減を繰り返しながら増加するパターンがあります。)

・参考情報

sar manual page

5.5.3. スワップ発生状況

sarコマンド [2] でシステムの統計情報を取得します。
-Sオプションでスワップ情報を表示させ、こちらを監視します。
# sar -S 5

一定間隔で結果が出力されます。

Linux 3.10.0-693.17.1.el7.x86_64 (localhost.localdomain)     2018年02月23日  _x86_64_        (1 CPU)

13時26分27秒 kbswpfree kbswpused  %swpused  kbswpcad   %swpcad
13時26分32秒    971700     76872      7.33      5740      7.47
13時26分37秒    971700     76872      7.33      5740      7.47
13時26分42秒    971700     76872      7.33      5740      7.47
13時26分47秒    971700     76872      7.33      5740      7.47

出力される情報は以下になります。

kbswpfree : スワップ領域の空き容量
kbswpused : スワップ領域の使用量
%swpused : スワップ領域の使用率
kbswpcad : キャッシュされたスワップメモリ容量
%swpcad : 使用されたスワップスペースに対する、キャッシュされたスワップメモリ使用率

・確認観点

kbswpusedと%swpusedが増加
物理メモリが不足し、スワップ領域が使用されている事を示します。
特定のユーザプロセスが大量にメモリを消費している事がなければ、物理メモリが
不足していると判断できますので、物理メモリの増設を検討する必要があります。

5.5.4. ディスクI/O

sarコマンド [2] でシステムの統計情報を取得します。
-dオプションでディスクI/O情報を表示させ、こちらを監視します。
# sar -d 5

一定間隔で結果が出力されます。

Linux 3.10.0-693.17.1.el7.x86_64 (localhost.localdomain)     2018年02月23日  _x86_64_        (1 CPU)

13時27分18秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
13時27分23秒  dev252-0     61.76      0.00    516.97      8.37      0.99     16.10     16.07     99.24
13時27分23秒  dev253-0     61.76      0.00    516.97      8.37      0.99     16.10     16.07     99.24
13時27分23秒  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

13時27分23秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
13時27分28秒  dev252-0    116.35      0.00    977.36      8.40      1.04      8.88      8.46     98.39
13時27分28秒  dev253-0    115.51      0.00    977.36      8.46      1.04      8.95      8.52     98.43
13時27分28秒  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

13時27分28秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
13時27分33秒  dev252-0    107.25      0.00    901.04      8.40      0.98      9.12      9.18     98.45
13時27分33秒  dev253-0    107.25      0.00    901.04      8.40      0.98      9.12      9.18     98.45
13時27分33秒  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

13時27分33秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
13時27分38秒  dev252-0    102.27      0.00    895.87      8.76      0.99      9.72      9.63     98.49
13時27分38秒  dev253-0    102.27      0.00    895.87      8.76      0.99      9.73      9.63     98.53
13時27分38秒  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

出力される情報は以下になります。

DEV : デバイス名
tps : 1秒あたりのリクエスト数(転送回数)
rd_sec/s : 1秒あたりの読み込みセクタ数
wr_sec/s : 1秒あたりの書き込みセクタ数
avgrq-sz : デバイスへのI/Oリクエストの平均ブロックサイズ
avgqu-sz : デバイスへのI/Oリクエストの平均待ちプロセス数(キューの長さ)
await : デバイスへのI/Oリクエストの平均待ち時間(msec)
svctm : デバイスへのI/Oリクエストの平均処理時間(msec)
%util : デバイスへのI/Oリクエスト中のCPU使用率

・確認観点

awaitとsvctmの差が大きくなっている
ディスク使用率が高く、待ち行列が発生している事を示しています。

svctmが大きく増減している
要求に対しての平均レスポンスタイムが安定していない事を示しています。
高負荷システムでは性能トラブルの原因にもなりますので、データベース用途に向かない
ディスクと考えられます。

%utilが継続的に100%になっている
ディスクの使用頻度が高い事を示しています。
性能トラブルが発生している場合はディスク性能がボトルネックになっていると考えられます。

5.5.5. ネットワーク使用状況

sarコマンド [2] でシステムの統計情報を取得します。
-nオプションでネットワーク情報を表示させ、こちらを監視します。
# sar -n DEV 5

一定間隔で結果が出力されます。

Linux 3.10.0-693.17.1.el7.x86_64 (localhost.localdomain)     2018年02月23日  _x86_64_        (1 CPU)

13時28分30秒     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
13時28分35秒      eth0      0.84      0.21      0.04      0.03      0.00      0.00      0.00
13時28分35秒        lo     12.76     12.76      2.64      2.64      0.00      0.00      0.00

13時28分35秒     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
13時28分40秒      eth0      0.62      0.21      0.03      0.05      0.00      0.00      0.00
13時28分40秒        lo     12.58     12.58      2.70      2.70      0.00      0.00      0.00

13時28分40秒     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
13時28分45秒      eth0      0.83      0.21      0.04      0.09      0.00      0.00      0.00
13時28分45秒        lo     12.19     12.19      2.55      2.55      0.00      0.00      0.00

13時28分45秒     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
13時28分50秒      eth0      0.64      0.21      0.03      0.09      0.00      0.00      0.00
13時28分50秒        lo     13.46     13.46      2.86      2.86      0.00      0.00      0.00

出力される情報は以下になります。

IFACE : インターフェイス名
rxpck/s : 1秒あたりの受信パケット数
txpck/s : 1秒あたりの送信パケット数
rxkB/s : 1秒あたりの受信バイト数(KB)
txkB/s : 1秒あたりの送信バイト数(KB)
rxcmp/s : 1秒あたりの受信圧縮パケット数
txcmp/s : 1秒あたりの送信圧縮パケット数
rxmcst/s : 1秒あたりのマルチキャスト受信パケット数

・確認観点

rxkB/sとtxkB/sの合計値が大きい
rxkB/sとtxkB/sは1秒間に「受信したデータ量」と「送信したデータ量」を示します。
これらの値の合計値が帯域を越えていないかを確認します。

5.5.6. プロセスのリソース使用状況

topコマンド [3] で稼働するプロセスのCPUおよびメモリの統計情報を取得します。

# top -b -d 5

取得した時点の結果が出力されます。

top - 06:23:46 up 7 days,  7:38,  2 users,  load average: 0.00, 0.01, 0.05
Tasks:  94 total,   2 running,  92 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.2 sy,  0.0 ni, 99.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  1016236 total,   157660 free,   128764 used,   729812 buff/cache
KiB Swap:  1048572 total,  1048188 free,      384 used.   679384 avail Mem

PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
24095 root      20   0  157588   2008   1448 R  0.4  0.2   0:00.46 top
1 root      20   0  128172   6748   3980 S  0.0  0.7   0:43.56 systemd
2 root      20   0       0      0      0 S  0.0  0.0   0:00.06 kthreadd

出力される情報は以下になります。

[各プロセスの情報のみ抜粋]
PID : プロセスID
USER : ユーザー名
PR : 優先度
NI : nice値
VIRT : 使用している仮想メモリ量
RES : 使用している物理メモリ量
SHR : 利用している共有メモリ量
%CPU : CPU 時間の占有率(総 CPU 時間のパーセンテージで表される)
%MEM : 利用可能な物理メモリの占有率
TIME+ : 開始してから利用した CPU 時間の総計
COMMAND : コマンドラインまたはプログラム名

iotopコマンド [4] で稼働するプロセスのディスクIOの統計情報を取得します。

# iotop -b -d 5

取得した時点の結果が出力されます。

Total DISK READ :       0.00 B/s | Total DISK WRITE :    1688.73 K/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:     734.68 K/s
TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN      IO    COMMAND
26896 be/4 postgres    0.00 B/s  741.11 K/s  0.00 % 13.46 % postgres: wal writer process
26901 be/4 postgres    0.00 B/s  947.62 K/s  0.00 %  0.16 % postgres: postgres postgres [local] COPY

出力される情報は以下になります。

[各プロセスの情報のみ抜粋]
TID : プロセスID
PRIO : IO優先度
USER : ユーザー
DISK READ : 1秒毎の読み込み量
DISK WRITE : 1秒毎の書き込み量
SWAPIN : スワップインに費やした時間の割合
IO : IO待ちに費やした時間の割合
COMMAND : マンドラインまたはプログラム名

・確認観点

リソース利用の割合が高いプロセスを特定します。PotgreSQLのプロセスが多くのリソースを消費している場合は、
「 任意の時間帯の処理実行状況 」を参照し、該当プロセスが実行中の処理の調査を実施して下さい。

・参考情報

[3]Linux User’s Manual TOP
[4]iostat manual page

5.6. データベース性能に影響を与える要素

性能トラブルを分析する際には、”特定の要素がデータベース性能にどのような影響を与えるか”を調査する必要があります。
データベースの性能に影響を与えると考えられる要素について、事前に洗い出し情報を蓄積しておきます。
以下に性能に影響を与える要素の一例を記載します。

表 5.7 データベース性能に影響を与える要素
項番 性能情報 種別 概要
1
ロングトランザクション
 瞬間値
ロングトランザクション
2 オブジェクトサイズ 瞬間値
データベースサイズ
テーブルサイズ
インデックスサイズ
3 オブジェクトスキャン 累計値
テーブルスキャン時の読み込み行数
インデックススキャンの割合
4 オブジェクトの状態 累計値
テーブル毎の不要領域確認
テーブル断片化
インデックス断片化
5 キャッシュヒット率 累計値
データベース毎のキャッシュヒット率
テーブル毎のキャッシュヒット率
インデックス毎のキャッシュヒット率
6 共有メモリ状況 瞬間値
共有メモリ状況
7 接続数 瞬間値
データベース毎の同時接続数
8 ロック状態 瞬間値
ロック待ち状態
ロック待ちSQL
9 デッドロック 累計値
デッドロック回数
デッドロックSQL
10 ディスクソート 累計値
SQLによるディスクソートの処理回数(work_memの不足回数)
ログメッセージの確認(ディスクソート)
11 待機イベント 累計値
待機イベントの発生回数

5.6.1. ロングトランザクション

実行中のトランザクション 内で長時間実行中となっているトランザクションが存在しないかを確認します。

5.6.2. オブジェクトサイズ

5.6.2.1. データベースサイズ

pg_databaseカタログ [1] には使用可能なデータベースの情報が格納されています。
以下のようなSQLを用いることで、データベース毎のサイズを取得することができます。
(サンプルSQL)
=#
SELECT
    datname,
    pg_size_pretty(pg_database_size(datname)) AS database_size
FROM
    pg_database;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]-+----------
datname       | postgres
database_size | 7861 kB
-[ RECORD 2 ]-+----------
datname       | testdb
database_size | 4280 MB
-[ RECORD 3 ]-+----------
datname       | template1
database_size | 7729 kB
-[ RECORD 4 ]-+----------
datname       | template0
database_size | 7729 kB

出力されるカラム情報は以下になります。

datname : データベース名
database_size : データベースサイズ

・確認観点

データベースサイズが顕著に増加
以下のような事象が考えられます。
1.レコードの増加に伴い、データベースサイズが増加している。
2.autovacuumが実行されているが、不要領域の回収を阻害する要因があるため、データベースが肥大化している。

・参考情報

[1]PostgreSQL 10.0文書 - 第51章 システムカタログ 51.15. pg_database

5.6.2.2. テーブルサイズ

pg_classカタログ [2] にはテーブルあるいはその他のオブジェクトの情報が格納されています。
以下のようなSQLを用いることで、テーブル毎のサイズを取得することができます。
(サンプルSQL)
=#
SELECT
    relname,
    reltuples,
    pg_size_pretty(pg_relation_size(oid)) AS tablesize
FROM
    pg_class
WHERE
    relnamespace = (SELECT oid FROM pg_namespace WHERE nspname='public')
    AND relkind in ('r', 't');
※ スキーマ名(nspname)は要件に応じて設定して下さい

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---------------
relname   | pgbench_tellers
reltuples | 10
tablesize | 8192 bytes
-[ RECORD 2 ]---------------
relname   | pgbench_branches
reltuples | 1
tablesize | 8192 bytes
-[ RECORD 3 ]---------------
relname   | pgbench_accounts
reltuples | 100000
tablesize | 13 MB
-[ RECORD 4 ]---------------
relname   | pgbench_history
reltuples | 41356
tablesize | 2136 kB
-[ RECORD 5 ]---------------
relname   | foo
reltuples | 5e+07
tablesize | 2111 MB

出力されるカラム情報は以下になります。

relname : テーブル名
reltuple : テーブルの推定行数
tablesize : テーブルサイズ

・確認観点

テーブルサイズが顕著に増加
以下のような事象が考えられます。
1.レコード数の増加に伴い、テーブルサイズが増加している。
2.autovacuumが実行されているが、不要領域の回収を阻害する要因があるため、テーブルが肥大化している。

・参考情報

[2]PostgreSQL 10.0文書 - 第51章 システムカタログ 51.11. pg_class

5.6.2.3. インデックスサイズ

pg_classカタログ [3] にはテーブルあるいはその他のオブジェクトの情報が格納されています。
以下のようなSQLを用いることで、インデックス毎のサイズを取得することができます。
(サンプルSQL)
=#
SELECT
    relname as indexname,
    pg_size_pretty(pg_relation_size(oid)) AS indexsize
FROM
    pg_class
WHERE
    relnamespace = (SELECT oid FROM pg_namespace WHERE nspname='public')
    AND relkind = 'i';
※ スキーマ名(nspname)は要件に応じて設定して下さい

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]--------------------
indexname | val_index
indexsize | 1071 MB
-[ RECORD 2 ]--------------------
indexname | pgbench_branches_pkey
indexsize | 16 kB
-[ RECORD 3 ]--------------------
indexname | pgbench_tellers_pkey
indexsize | 16 kB
-[ RECORD 4 ]--------------------
indexname | pgbench_accounts_pkey
indexsize | 2208 kB
-[ RECORD 5 ]--------------------
indexname | foo_pkey
indexsize | 1071 MB

出力されるカラム情報は以下になります。

indexname : インデックス名
indexsize : インデックスサイズ

・確認観点

インデックスサイズが顕著に増加
インデックスサイズが肥大化している事を示しています。
レコード量の増加以外にインデックスの断片化が発生している可能性がありますので、
pgstatindex [4] を使用して、インデックスの断片化を確認して下さい。
必要であれば、REINDEXやインデックスの再作成を検討して下さい。

・参考情報

[3]PostgreSQL 10.0文書 - 第51章 システムカタログ 51.11. pg_class
[4]PostgreSQL 10.0文書 - 付録F 追加で提供されるモジュール F.31. pgstattuple(pgstatindex)

5.6.3. オブジェクトスキャン

5.6.3.1. テーブルスキャン時の読み込み行数

pg_stat_user_tablesビュー [5] では、テーブルスキャンが発生した回数と読み込まれた行数の累計値が収集されています。
以下のようなSQLを用いることで、テーブルスキャン時の読み込み行数を取得することができます。
(サンプルSQL)
=#
SELECT
    relname,
    seq_scan,
    seq_tup_read,
    seq_tup_read/seq_scan AS tup_per_read
FROM
    pg_stat_user_tables
WHERE
    seq_scan > 0
ORDER BY
    tup_per_read DESC;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]+-----------------
relname      | foo
seq_scan     | 11
seq_tup_read | 200000000
tup_per_read | 18181818
-[ RECORD 2 ]+-----------------
relname      | pgbench_accounts
seq_scan     | 3
seq_tup_read | 300000
tup_per_read | 100000
-[ RECORD 3 ]+-----------------
relname      | pgbench_tellers
seq_scan     | 50975
seq_tup_read | 509750
tup_per_read | 10
-[ RECORD 4 ]+-----------------
relname      | pgbench_branches
seq_scan     | 50979
seq_tup_read | 50979
tup_per_read | 1

出力されるカラム情報は以下になります。

relname : テーブル名
seq_scan: シーケンシャルスキャンの実行回数
seq_tup_read : シーケンシャルスキャンによって取り出された行数
seq_tup_read/seq_scan AS tup_per_read : シーケンシャルスキャン1回で取り出されてた平均行数

・確認観点

シーケンシャルスキャンの実行回数が顕著に増加した場合
以下のような事象が考えられます。
・インデックススキャンからシーケンシャルスキャンに実行計画が変わっている。

シーケンシャルスキャン1回で取り出されてた平均行数が数万行以上
以下のような事象が考えられます。
・全てのレコードを参照するSQLが実行されている。
・インデックスの定義漏れでシーケンシャルスキャンが実行されている。

・参考情報

[5]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_stat_all_tablesビュー(pg_stat_user_tablesビュー)

5.6.3.2. インデックススキャンの割合

pg_stat_user_tablesビュー [6] では、インデックススキャンが発生した回数と読み込まれた行数の累計値が収集されています。
以下のようなSQLを用いることで、インデックススキャンの割合を取得することができます。
(サンプルSQL)
=#
SELECT
    relname,
    seq_scan,
    idx_scan,
    CASE
        WHEN (seq_scan + idx_scan) = 0 THEN 0.00
        ELSE round(100 * idx_scan/(seq_scan + idx_scan),2)
    END AS idx_scan_ratio
FROM
    pg_stat_user_tables
ORDER BY
    idx_scan_ratio;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]--+-----------------
relname        | pgbench_branches
seq_scan       | 50979
idx_scan       | 0
idx_scan_ratio | 0.00
-[ RECORD 2 ]--+-----------------
relname        | pgbench_tellers
seq_scan       | 50975
idx_scan       | 0
idx_scan_ratio | 0.00
-[ RECORD 3 ]--+-----------------
relname        | foo
seq_scan       | 11
idx_scan       | 7
idx_scan_ratio | 38.00
-[ RECORD 4 ]--+-----------------
relname        | pgbench_accounts
seq_scan       | 3
idx_scan       | 101950
idx_scan_ratio | 99.00
-[ RECORD 5 ]--+-----------------
relname        | pgbench_history
seq_scan       | 0
idx_scan       |
idx_scan_ratio |

出力されるカラム情報は以下になります。

relname : テーブル名
seq_scan: シーケンシャルスキャンの実行回数
idx_scan : インデックススキャンの実行回数
round(100 * idx_scan/(seq_scan + idx_scan),2) : インデックススキャンの割合

・確認観点

シーケンシャルスキャンの実行回数が顕著に増加した場合
以下のような事象が考えられます。
・インデックススキャンからシーケンシャルスキャンに実行計画が変わっている。

シーケンシャルスキャン1回で取り出されてた平均行数が数万行以上
以下のような事象が考えられます。
・インデックスの定義漏れでシーケンシャルスキャンが実行されている。

・参考情報

[6]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_stat_all_tablesビュー(pg_stat_user_tablesビュー)

5.6.4. オブジェクトの状態

5.6.4.1. テーブル毎の不要領域確認

pg_stat_user_tablesビュー [7] では、推定値となりますが有効行と不要行の現在値が収集されています。
以下のようなSQLを用いることで、全体の行数の内と不要行の割合から不要領域を取得します。
(サンプルSQL)
=#
SELECT
    relname,
    n_live_tup,
    n_dead_tup,
    CASE n_dead_tup
        WHEN 0 THEN 0
        ELSE round(n_dead_tup*100/(n_live_tup+n_dead_tup),2)
    END AS ratio
FROM
    pg_stat_user_tables;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]----------------
relname    | foo
n_live_tup | 50000000
n_dead_tup | 0
ratio      | 0
-[ RECORD 2 ]----------------
relname    | pgbench_history
n_live_tup | 41819
n_dead_tup | 0
ratio      | 0
-[ RECORD 3 ]----------------
relname    | pgbench_accounts
n_live_tup | 100000
n_dead_tup | 1813
ratio      | 1.00
-[ RECORD 4 ]----------------
relname    | pgbench_branches
n_live_tup | 1
n_dead_tup | 0
ratio      | 0
-[ RECORD 5 ]----------------
relname    | pgbench_tellers
n_live_tup | 10
n_dead_tup | 22
ratio      | 68.00

出力されるカラム情報は以下になります。

relname : テーブル名
n_live_tup : 有効行の推定値
n_dead_tup : 不要行の推定値
round(n_dead_tup*100/(n_live_tup+n_dead_tup),2) AS ratio : 不要領域の割合

・確認観点

不要領域の割合が、長時間の間、autovacuum_vacuum_scale_factorパラメータ以上の場合
不要領域の割合が、長時間の間、autovacuum_vacuum_scale_factorパラメータ [8] 以上の場合、以下のような事象が考えられます。
1.autovacuumが該当テーブルで実行されていない。
2.autovacuumが実行されているが、不要領域の回収を阻害する要因がある。

・参考情報

[7]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_stat_all_tablesビュー(pg_stat_user_tablesビュー)
[8]PostgreSQL 10.0文書 - 第19章 サーバの設定 19.10. 自動Vacuum作業 autovacuum_vacuum_scale_factorパラメータ

5.6.4.2. テーブル断片化

pgstattupleモジュール [10] では、現在のタプルレベルの統計情報を入手するための各種関数が提供されています。
pgstattuple関数だと常に全件走査を実行し、有効タプルと無効タプルの正確な数(およびそのサイズ)と
空き領域を返しますが、性能への影響を考え、pgstattuple_approx関数を使用しています。
こちらは全件走査を避け、無効タプルの正確な統計情報および有効タプルと空き領域の数とサイズは近似値となります。
以下のようなSQLを用いることで、テーブルの断片化情報を取得することができます。
(サンプルSQL)
SELECT
    objectname,
    pg_size_pretty(pg_relation_size(objectname)) AS total_size,
    app.approx_tuple_count,
    app.approx_tuple_percent,
    app.dead_tuple_count,
    app.dead_tuple_percent,
    app.approx_free_space,
    app.approx_free_percent
FROM (
    SELECT
        *, quote_ident(schemaname) || '.' || quote_ident(relname) AS objectname
    FROM
        pg_stat_user_tables
) AS t, pgstattuple_approx(objectname::regclass) AS app
ORDER BY app.approx_free_percent DESC;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]--------+------------------------
objectname           | public.pgbench_branches
total_size           | 8192 bytes
approx_tuple_count   | 1
approx_tuple_percent | 10.9375
dead_tuple_count     | 0
dead_tuple_percent   | 0
approx_free_space    | 7296
approx_free_percent  | 89.0625
-[ RECORD 2 ]--------+------------------------
objectname           | public.pgbench_tellers
total_size           | 8192 bytes
approx_tuple_count   | 10
approx_tuple_percent | 4.39453125
dead_tuple_count     | 22
dead_tuple_percent   | 9.66796875
approx_free_space    | 6176
approx_free_percent  | 75.390625
-[ RECORD 3 ]--------+------------------------
objectname           | public.test
total_size           | 21 MB
approx_tuple_count   | 200000
approx_tuple_percent | 41.1436264124294
dead_tuple_count     | 0
dead_tuple_percent   | 0
approx_free_space    | 12801120
approx_free_percent  | 58.8563735875706
-[ RECORD 4 ]--------+------------------------
objectname           | public.pgbench_accounts
total_size           | 13 MB
approx_tuple_count   | 100000
approx_tuple_percent | 88.4461545658683
dead_tuple_count     | 0
dead_tuple_percent   | 0
approx_free_space    | 269044
approx_free_percent  | 1.96660390157186
-[ RECORD 5 ]--------+------------------------
objectname           | public.pgbench_history
total_size           | 2136 kB
approx_tuple_count   | 41817
approx_tuple_percent | 91.7683462078652
dead_tuple_count     | 0
dead_tuple_percent   | 0
approx_free_space    | 5304
approx_free_percent  | 0.242494733146067

出力されるカラム情報は以下になります。

objectname : テーブル名
total_size : テーブルサイズ
approx_tuple_count : 有効タプル数(推定)
approx_tuple_percent : 有効タプルの割合
dead_tuple_count : 無効タプル数(実測)
dead_tuple_percent : 無効タプルの割合
approx_free_space : 空き領域の合計バイト数(推定)
approx_free_percent : 空き領域の割合

・確認観点

オブジェクトサイズが大きくなっており、空き領域の割合が高い場合
テーブルが肥大化していることを示しています。
肥大化したテーブルサイズを縮小させるには、VACUUM FULLを実行するか、
テーブルを再作成する必要があります。(業務影響大のため、要検討)

オブジェクトサイズが大きくなっており、無効タプルの割合が高い場合
以下の事象が考えられます。
1. VACUUMが該当テーブルで実行されていない。
2. VACUUMが実行されているが、不要領域の回収を阻害する要因がある。

VACUUMが実行されていない場合は、autovacuumが実行される為の閾値 [9] が
高く設定されている可能性がありますので、見直しを検討してください。
不要領域が回収されていない場合は、ロングトランザクションが
VACUUM処理を阻害している可能性があります。
稼動統計情報からロングトランザクションが発生していないかを確認してください。

・参考情報

[9]

PostgreSQL 10.0文書 - 第24章 定常的なデータベース保守作業 24.1. 定常的なバキューム作業 24.1.6. 自動バキュームデーモン

バキューム基礎閾値 + バキューム規模係数 * タプル数
(autovacuum_vacuum_threshold + autovacuum_vacuum_scale_factor * pg_class.reltuples)
[10]PostgreSQL 10.0文書 - 付録F 追加で提供されるモジュール F.31. pgstattuple

5.6.4.3. インデックス断片化

pgstattupleモジュール [12] では、現在のタプルレベルの統計情報を入手するための各種関数が提供されています。
pgstatindex関数だとB-treeインデックスに関する情報を示すレコードを返却しますが、GINインデックスに関する情報は
pgstatginindex関数を使用してください。
以下のようなSQLを用いることで、インデックスの断片化情報を取得することができます。
(サンプルSQL)
SELECT
    objectname,
    pg_size_pretty(pg_relation_size(objectname)) AS total_size,
    app.tree_level,
    app.index_size,
    app.root_block_no,
    app.internal_pages,
    app.leaf_pages,
    app.empty_pages,
    app.deleted_pages,
    app.avg_leaf_density,
    app.leaf_fragmentation
FROM (
    SELECT
        *, quote_ident(schemaname) || '.' || quote_ident(indexrelname) AS objectname
    FROM
        pg_stat_user_indexes
) AS t, pgstatindex(objectname::regclass) AS app
ORDER BY app.leaf_fragmentation DESC;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]------+-----------------------------
objectname         | public.pgbench_branches_pkey
total_size         | 16 kB
tree_level         | 0
index_size         | 16384
root_block_no      | 1
internal_pages     | 0
leaf_pages         | 1
empty_pages        | 0
deleted_pages      | 0
avg_leaf_density   | 0.29
leaf_fragmentation | 0
-[ RECORD 2 ]------+-----------------------------
objectname         | public.pgbench_tellers_pkey
total_size         | 16 kB
tree_level         | 0
index_size         | 16384
root_block_no      | 1
internal_pages     | 0
leaf_pages         | 1
empty_pages        | 0
deleted_pages      | 0
avg_leaf_density   | 2.5
leaf_fragmentation | 0
-[ RECORD 3 ]------+-----------------------------
objectname         | public.pgbench_accounts_pkey
total_size         | 2208 kB
tree_level         | 1
index_size         | 2260992
root_block_no      | 3
internal_pages     | 1
leaf_pages         | 274
empty_pages        | 0
deleted_pages      | 0
avg_leaf_density   | 91.46
leaf_fragmentation | 0
-[ RECORD 4 ]------+-----------------------------
objectname         | public.test_pkey
total_size         | 11 MB
tree_level         | 2
index_size         | 11247616
root_block_no      | 412
internal_pages     | 4
leaf_pages         | 547
empty_pages        | 0
deleted_pages      | 821
avg_leaf_density   | 90
leaf_fragmentation | 0

出力されるカラム情報は以下になります。

objectname : インデックス名
total_size : インデックスサイズ
tree_level : ルートページのツリーレベル
index_size : バイト単位のインデックスサイズ
root_block_no : ルートページの場所(存在しない場合はゼロ)
internal_pages : 「内部」(上位レベル)ページ数
leaf_pages : リーフページ数
empty_pages : 空ページ数
deleted_pages : 削除ページ数
avg_leaf_density : リーフページの平均密度
leaf_fragmentation : リーフページの断片化

・確認観点

リーフページの断片化の割合が高い場合
インデックスが断片化していることを示しています。
REINDEXの実行、またはインデックスの再作成を検討する必要があります。
また、CREATE INDEXコマンドのCONCURRENTLYオプション [11] を指定することで、
PostgreSQLは、対象テーブルに対する同時挿入、更新、削除を防止するような
ロックを獲得せずにインデックスを作成することが可能です。

・参考情報

[11]PostgreSQL 10.0文書 - SQLコマンド CREATE INDEX
[12]PostgreSQL 10.0文書 - 付録F 追加で提供されるモジュール F.31. pgstattuple(pgstatindex)

5.6.5. キャッシュヒット率

5.6.5.1. データベース毎のキャッシュヒット率

pg_stat_databaseビュー [13] では、データベース毎にバッファキャッシュから読み込んだバッファヒット数と
ディスクから読み込んだディスクブロック数の累計値が収集されています。
以下のようなSQLを用いることで、全体のブロック数とバッファキャッシュから読み込んだバッファヒット数の割合から
キャッシュヒット率を取得することができます。
(サンプルSQL)
=#
SELECT
    datname,
    blks_hit,
    blks_read,
    round(blks_hit*100/(blks_hit+blks_read), 2) AS cache_hit_ratio
FROM
    pg_stat_database
WHERE
    blks_read > 0;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---+----------
datname         | postgres
blks_hit        | 785946
blks_read       | 976
cache_hit_ratio | 99.00
-[ RECORD 2 ]---+----------
datname         | testdb
blks_hit        | 210105873
blks_read       | 3629745
cache_hit_ratio | 98.00

出力されるカラム情報は以下になります。

datname : データベース名
blks_hit : キャッシュから読み取られたブロック数
(PosgreSQLのshared_buffersでのキャッシュヒットのみを含み、OSのファイルシステムキャッシュはblks_hitに含まない)
blks_read : 読み取られたディスクブロック数
round(blks_hit*100/(blks_hit+blks_read), 2) AS cache_hit_ratio : キャッシュヒット率(%)

・確認観点

データベースのキャッシュヒット率が低下している場合
以下のような事象が考えられます。
1. アクセスするデータ量に対して、shared_buffersの値が不足している。
2. テーブルへのシーケンシャルスキャンもしくはインデックススキャンで多くのレコードが読み取られた。
3. あまり参照されていないデータにアクセスするSQLが実行された。

キャッシュヒット率が低い場合は、CPU利用率を確認し、iowaitの値が高くなっているか否かを確認します。
(iowaitの値が高くなっていない場合は、OSのファイルシステムキャッシュにて、キャッシュヒットしている場合があります。)
また、キャッシュヒット率が低い場合は、 「テーブル毎のキャッシュヒット率」 や 「SQLのキャッシュヒット率」 を確認し、
キャッシュヒット率低下の要因となっているテーブルやSQLを確認します。

・参考情報

[13]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ

5.6.5.2. テーブル毎のキャッシュヒット率

pg_statio_user_tablesビュー [14] では、テーブル毎にバッファキャッシュから読み込んだバッファヒット数と
ディスクから読み込んだディスクブロック数の累計値が収集されていますので、こちらを監視対象とします。
以下のようなSQLを用いることで、全体のブロック数とバッファキャッシュから読み込んだバッファヒット数の割合から
キャッシュヒット率を取得することができます。
(サンプルSQL)
=#
SELECT
    relname,
    heap_blks_hit,
    heap_blks_read,
    round(heap_blks_hit*100/(heap_blks_hit+heap_blks_read), 2) AS cache_hit_ratio
FROM
    pg_statio_user_tables
WHERE
    heap_blks_read > 0
ORDER BY
    cache_hit_ratio;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---+-----------------
relname         | foo
heap_blks_hit   | 51259357
heap_blks_read  | 2938831
cache_hit_ratio | 94.00
-[ RECORD 2 ]---+-----------------
relname         | pgbench_accounts
heap_blks_hit   | 180899
heap_blks_read  | 8468
cache_hit_ratio | 95.00
-[ RECORD 3 ]---+-----------------
relname         | pgbench_history
heap_blks_hit   | 53243
heap_blks_read  | 330
cache_hit_ratio | 99.00
-[ RECORD 4 ]---+-----------------
relname         | pgbench_tellers
heap_blks_hit   | 102129
heap_blks_read  | 10
cache_hit_ratio | 99.00
-[ RECORD 5 ]---+-----------------
relname         | pgbench_branches
heap_blks_hit   | 102143
heap_blks_read  | 12
cache_hit_ratio | 99.00

出力されるカラム情報は以下になります。

relname : テーブル名
heap_blks_hit : キャッシュから読み取られたブロック数
heap_blks_read: 読み取られたディスクブロック数
round(heap_blks_hit*100/(heap_blks_hit+heap_blks_read), 2) AS cache_hit_ratio キャッシュヒット率(%)

・確認観点

テーブルのキャッシュヒット率が低下している場合
以下のような事象が考えられます。
1. アクセスするデータ量に対して、shared_buffersの値が不足している。
2. テーブルへのシーケンシャルスキャンもしくはインデックススキャンで多くのレコードが読み取られた。
3. あまり参照されていないデータにアクセスするSQLが実行された。

・参考情報

[14]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_statio_all_tablesビュー(pg_statio_user_tablesビュー)

5.6.5.3. インデックス毎のキャッシュヒット率

pg_statio_user_indexesビュー [15] では、インデックスにおけるバッファヒット数とインデックスから読み取られた
ディスクブロック数の累計値が収集されています。
以下のようなSQLを用いることで、全体のブロック数とインデックスにおけるバッファヒット数の割合から
キャッシュヒット率を取得することができます。
(サンプルSQL)
=#
SELECT
    indexrelname,
    relname,
    idx_blks_hit,
    idx_blks_read,
    round(idx_blks_hit*100/(idx_blks_hit+idx_blks_read), 2) AS cache_hit_ratio
FROM
    pg_statio_user_indexes
WHERE
    idx_blks_read > 0
ORDER BY
    cache_hit_ratio;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---+----------------------
indexrelname    | val_index
relname         | foo
idx_blks_hit    | 123
idx_blks_read   | 278892
cache_hit_ratio | 0.00
-[ RECORD 2 ]---+----------------------
indexrelname    | pgbench_branches_pkey
relname         | pgbench_branches
idx_blks_hit    | 42
idx_blks_read   | 6
cache_hit_ratio | 87.00
-[ RECORD 3 ]---+----------------------
indexrelname    | pgbench_tellers_pkey
relname         | pgbench_tellers
idx_blks_hit    | 34
idx_blks_read   | 4
cache_hit_ratio | 89.00
-[ RECORD 4 ]---+----------------------
indexrelname    | foo_pkey
relname         | foo
idx_blks_hit    | 157394582
idx_blks_read   | 400482
cache_hit_ratio | 99.00
-[ RECORD 5 ]---+----------------------
indexrelname    | pgbench_accounts_pkey
relname         | pgbench_accounts
idx_blks_hit    | 208539
idx_blks_read   | 1105
cache_hit_ratio | 99.00

出力されるカラム情報は以下になります。

indexrelname : インデックス名
relname : インデックスが定義されたテーブル名
idx_blks_hit : キャッシュから読み取られたブロック数
idx_blks_read: 読み取られたディスクブロック数
round(idx_blks_hit*100/(idx_blks_hit+idx_blks_read), 2) AS cache_hit_ratio : キャッシュヒット率

・確認観点

インデックスのキャッシュヒット率が低下している場合
以下のような事象が考えられます。
1. アクセスするデータ量に対して、shared_buffersの値が不足してる(レコード数の増加などが考えられます)。
2. インデックスを利用して多くのデータが読み取られた。
3. あまり参照されてないインデックス(データ)にアクセスするSQLが実行された。

・参考情報

[15]pg_statio_all_indexesビュー(pg_statio_user_indexesビュー)

5.6.6. 共有メモリ状況

5.6.6.1. 共有メモリ状況

pg_buffercacheビュー [16] では、現在の共有バッファの情報が収集されています。
以下のようなSQLを用いることで、共有バッファの状態を取得することができます。
ただし、pg_buffercacheビュー [16] にアクセスがあると、ビューが表示する全てのバッファ状態をコピーするために
十分な期間、内部バッファマネージャはロックを取得しますので、頻繁にアクセスするとデータベース性能に多少影響が発生することにご注意願います。
(サンプルSQL)
SELECT
    c.relname,
    count(*) AS buffers
FROM
    pg_buffercache AS b
INNER JOIN
    pg_class AS c
    ON b.relfilenode = pg_relation_filenode(c.oid)
    AND b.reldatabase IN (0, (SELECT oid FROM pg_database WHERE datname = current_database()))
GROUP BY c.relname
ORDER BY 2 DESC;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]-------------------------------------
relname | test
buffers | 2659
-[ RECORD 2 ]-------------------------------------
relname | pgbench_accounts
buffers | 1670
-[ RECORD 3 ]-------------------------------------
relname | test_pkey
buffers | 1373
-[ RECORD 4 ]-------------------------------------
relname | pgbench_accounts_pkey
buffers | 276
    ：

出力されるカラム情報は以下になります。

relname : オブジェクト名(テーブル、インデックスなどの名前)
buffers : 共有キャッシュ内のバッファ数

・確認観点

特定のオブジェクトのバッファ数が共有バッファ上に少ない場合
以下のような事象が考えられます。
1. 共有メモリ領域が小さいために、特定のオブジェクトのバッファを載せきれていない
2. アクセス頻度が少ないため、共有バッファ上からキャッシュアウトされやすくなっている

・参考情報

[16](1, 2) PostgreSQL 10.0文書 - 付録F 追加で提供されるモジュール F.25. pg_buffercache

5.6.7. 接続数

5.6.7.1. データベース毎の同時接続数

pg_stat_activityビュー [17] では、サーバプロセス毎の情報が収集されています。
以下のようなSQLを用いることで、表示されているプロセスの数を現在の接続数として取得することができます。
(サンプルSQL)
=#
SELECT
    datname,
    count(*) AS connections
FROM
    pg_stat_activity
WHERE
    datname IS NOT NULL
GROUP BY
    datname;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]---------
datname     | postgres
connections | 1
-[ RECORD 2 ]---------
datname     | testdb
connections | 1

出力されるカラム情報は以下になります。

datname : データベース名
connections : 現在の接続数

・確認観点

現在の接続数が徐々に増加
接続数が増加している事を示しています。
稼動統計情報を確認し、トランザクションが閉じられないまま長時間が経過している状態
(ロングトランザクション)になっていないかを確認します。

・参考情報

[17]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ pg_stat_activityビュー

5.6.8. ロック状態

5.6.8.1. ロック待ち状態

pg_locksビュー [18] では、データベース内でアクティブなプロセスによって保持されたロックに関する情報の現在値が収集されています。
以下のようなSQLを用いることで、ロック待ちの状態を取得することができます。
(サンプルSQL)
=#
SELECT
    date_trunc('second', current_timestamp(0)) AS time,
    blocked_locks.pid AS blocked_pid,
    blocked_activity.usename AS blocked_user,
    blocking_locks.pid AS blocking_pid,
    blocking_activity.usename AS blocking_user,
    blocked_activity.query AS blocked_statement,
    blocking_activity.query AS current_statement_in_blocking_process,
    (current_timestamp - blocked_activity.xact_start)::interval(3) AS duration
FROM
    pg_catalog.pg_locks blocked_locks
JOIN
    pg_catalog.pg_stat_activity blocked_activity
    ON blocked_activity.pid = blocked_locks.pid
JOIN
    pg_catalog.pg_locks AS blocking_locks
    ON blocking_locks.locktype = blocked_locks.locktype
    AND blocking_locks.DATABASE IS NOT DISTINCT FROM blocked_locks.DATABASE
    AND blocking_locks.relation IS NOT DISTINCT FROM blocked_locks.relation
    AND blocking_locks.page IS NOT DISTINCT FROM blocked_locks.page
    AND blocking_locks.tuple IS NOT DISTINCT FROM blocked_locks.tuple
    AND blocking_locks.virtualxid IS NOT DISTINCT FROM blocked_locks.virtualxid
    AND blocking_locks.transactionid IS NOT DISTINCT FROM blocked_locks.transactionid
    AND blocking_locks.classid IS NOT DISTINCT FROM blocked_locks.classid
    AND blocking_locks.objid IS NOT DISTINCT FROM blocked_locks.objid
    AND blocking_locks.objsubid IS NOT DISTINCT FROM blocked_locks.objsubid
    AND blocking_locks.pid != blocked_locks.pid
JOIN
    pg_catalog.pg_stat_activity blocking_activity
    ON blocking_activity.pid = blocking_locks.pid
WHERE
    NOT blocked_locks.GRANTED;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]-------------------------+------------------------------------------------------
time                                  | 2018-03-01 18:05:46+09
blocked_pid                           | 32603
blocked_user                          | postgres
blocking_pid                          | 32522
blocking_user                         | postgres
blocked_statement                     | SELECT * FROM pgbench_accounts;
current_statement_in_blocking_process | LOCK TABLE pgbench_accounts IN ACCESS EXCLUSIVE MODE;
duration                              | 00:03:05.212

出力されるカラム情報は以下になります。

time : 取得時間
blocked_pid : ロック待ちプロセスID
blocked_user : ロック待ちユーザ
blocking_pid : ロックしているプロセスID
blocking_user : ロックしているユーザ
blocked_statement : ロック待ちSQL文
current_statement_in_blocking_process : ロックしているSQL文
duration : トランザクションの実行時間

・確認観点

大量のプロセスでロック待ちが発生
以下の様な事象が考えられます。
1. 特定のプロセスで実行された処理が取得するロックにより他の処理でロックが取得できていない。
2. 該当のSQLで遅延が発生し、本来完了後に実行されるはずの他の処理でロックが取得できなかった。

これらの事象を解消するには、ロックしているSQLを確認して下さい。
VACUUM FULLやREINDEXなど強いロックを必要とする処理であれば、実行時間の変更や代替案を検討して下さい。
該当のSQLが遅延しているのであれば、原因を調査し、遅延を解消する必要があります。

・参考情報

[18]PostgreSQL 10.0文書 - 第51章 システムカタログ 51.73. pg_locks

5.6.8.2. ロック待ちSQL

log_lock_waitsを有効にすることでプロセスでデッドロックのタイムアウト時間よりもロック待ちが発生した場合、自動的にログに出力します。
特定の処理がロック待ちの原因になっていないかを確認するために監視対象とします。
監視対象ログファイル: PostgreSQLログ
監視対象文字列：LOG、still waiting

LOG:  process 11856 still waiting for AccessShareLock on relation 24880 of database 16384 after 1000.324 ms at character 15
DETAIL:  Process holding the lock: 11854. Wait queue: 11856.
STATEMENT:  SELECT * FROM pgbench_accounts;

・確認観点

ロック待ちを検知
該当のSQLでロック待ちが発生している事を示しています。
ロック待ちが発生している該当のSQLを確認し、ロック待ちを引き起こしている原因となる事象を確認して下さい。

5.6.9. デッドロック

5.6.9.1. デッドロック回数

pg_stat_databaseビュー [19] では、データベース内で検知されたデッドロック数の累積値が収集されています。
以下のようなSQLを用いることで、デッドロックの発生回数を取得することができます。
(サンプルSQL)
=#
SELECT
    datname,
    deadlocks
FROM
    pg_stat_database;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]--------
datname   | postgres
deadlocks | 0
-[ RECORD 2 ]--------
datname   | testdb
deadlocks | 1
-[ RECORD 3 ]--------
datname   | template1
deadlocks | 0
-[ RECORD 4 ]--------
datname   | template0
deadlocks | 0

出力されるカラム情報は以下になります。

datname : データベース名
deadlocks : デッドロック発生回数

・確認観点

デッドロック回数が増加
デッドロックが頻発している事を示しています。
ログメッセージを確認し、デッドロックが発生した該当のSQLを特定した後、
該当SQLを実行するアプリケーションにてデッドロックを引き起こす制御になっていないかを確認して下さい。

・参考情報

[19]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ

5.6.9.2. デッドロックSQL

log_lock_waitsを有効にすることでプロセスでデッドロック [20] が発生した場合、自動的にログに出力します。
特定の処理でデッドロックが発生していないかを確認するために監視対象とします。
監視対象ログファイル: PostgreSQLログ
監視対象文字列：ERROR、deadlock

ERROR:  deadlock detected
DETAIL:  Process 11957 waits for AccessExclusiveLock on relation 24880 of database 16384; blocked by process 11948.
        Process 11948 waits for AccessExclusiveLock on relation 24874 of database 16384; blocked by process 11957.
        Process 11957: LOCK TABLE pgbench_accounts IN ACCESS EXCLUSIVE MODE;
        Process 11948: LOCK TABLE pgbench_history IN ACCESS EXCLUSIVE MODE;
HINT:  See server log for query details.
STATEMENT:  LOCK TABLE pgbench_accounts IN ACCESS EXCLUSIVE MODE;
LOG:  process 11948 acquired AccessExclusiveLock on relation 24874 of database 16384 after 5009.589 ms
STATEMENT:  LOCK TABLE pgbench_history IN ACCESS EXCLUSIVE MODE;

・確認観点

デッドロックを検知
該当のSQLでデッドロックが発生した事を示しています。
deadlock_timeoutパラメータ [21] に指定した時間毎の検出処理でデッドロックが検出された場合、片方のトランザクション処理は
強制的に終了され、もう片方のトランザクション処理は完了されます。
デッドロックが発生した該当のSQLを確認し、アプリケーション側でデッドロックを引き起こす制御になっていないかを確認して下さい。

・参考情報

[20]PostgreSQL 10.0文書 第13章 同時実行制御 13.3. 明示的ロック 13.3.4. デッドロック
[21]PostgreSQL 10.0文書 - 第19章 サーバの設定 19.12. ロック管理 deadlock_timeoutパラメータ

5.6.10. ディスクソート

5.6.10.1. SQLによるディスクソートの処理回数(work_memの不足回数)

pg_stat_databaseビュー [22] では、問い合わせによって書き出された一時ファイルの個数とデータ量の累計値が収集されています。
work_memのサイズ [23] が不足している場合、一時ファイルに書き出して処理を行うので、この値を監視対象としています。
以下のようなSQLを用いることで、ディスクソートの発生情報を取得することができます。
(サンプルSQL)
=#
SELECT
    datname,
    temp_files,
    pg_size_pretty(temp_bytes) AS temp_bytes ,
    pg_size_pretty(round(temp_bytes/temp_files,2)) AS temp_file_size
FROM
    pg_stat_database
WHERE
    temp_files > 0;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]--+-------
datname        | testdb
temp_files     | 46
temp_bytes     | 10 GB
temp_file_size | 233 MB

出力されるカラム情報は以下になります。

datname : データベース名
temp_files : SQLによって書き出された一時ファイルの個数
pg_size_pretty(temp_bytes) AS temp_bytes : 書き出された一時ファイルの合計サイズ
pg_size_pretty(round(temp_bytes/temp_files,2)) AS temp_file_size : 一時ファイルの平均サイズ

・確認観点

一時ファイルが作成されている場合
ソート処理やハッシュ処理でメモリ(work_mem) [23] が不足し、作業用の一時ファイルがディスク上に書き出されています。
OSのメモリ使用量に空き領域がある場合は、work_memの設定値を大きくすることを検討します。

・参考情報

[22]PostgreSQL 10.0文書 - 第28章 データベース活動状況の監視 28.2. 統計情報コレクタ
[23](1, 2) PostgreSQL 10.0文書 - 第19章 サーバの設定 19.4. 資源の消費 work_memパラメータ

5.6.10.2. ログメッセージの確認(ディスクソート)

log_temp_filesで指定したサイズ以上の一時ファイルが作成された場合、ログに出力します。
一時ファイルによるディスクアクセスが発生していないかを確認するために監視対象とします。
監視対象ログファイル: PostgreSQLログ
監視対象文字列：LOG、temporary file

LOG:  temporary file: path "base/pgsql_tmp/pgsql_tmp1125.19", size 14131200
STATEMENT:  SELECT COUNT(*) FROM (SELECT i FROM generate_series(1,1000000) AS i ORDER BY i DESC limit 500000 OFFSET 0) AS x;
LOG:  temporary file: path "base/pgsql_tmp/pgsql_tmp1125.18", size 14000000
STATEMENT:  SELECT COUNT(*) FROM (SELECT i FROM generate_series(1,1000000) AS i ORDER BY i DESC limit 500000 OFFSET 0) AS x;

・確認観点

一時ファイルを検知
該当のSQLで一時ファイルを作成している事を示しています。
該当のSQLにEXPLAIN (ANALYZE, BUFFERS)を付与し、実際に実行した情報を確認して下さい。
ハッシュ処理やソート処理で一時ファイルが作成されているようであれば、work_memのサイズ [24] が足りていませんので、
work_memサイズ [24] の増加を検討して下さい。

・参考情報

[24](1, 2) PostgreSQL 10.0文書 - 第19章 サーバの設定 19.4. 資源の消費 work_memパラメータ

5.6.11. 待機イベント

5.6.11.1. 待機イベントの発生回数

外部ツールのpg_wait_sampling [25] を利用することで、待機イベントの発生回数を取集することが可能です。

pg_wait_samplingが提供するpg_wait_sampling_profileビューには、待機イベントと発生回数が記録されています。
以下のようなSQLを用いることで、待機イベントとその発生回数を確認することが可能です。
(サンプルSQL)
=#
SELECT
    event_type,
    event,
    SUM(count)
FROM
    pg_wait_sampling_profile
WHERE
    event IS NOT NULL
GROUP BY
    event_type, event
ORDER BY
    sum(count) DESC;

SQLの実行結果は以下の通りです。

-[ RECORD 1 ]-------------------
event_type | LWLock
event      | WALWriteLock
sum        | 984
-[ RECORD 2 ]-------------------
event_type | Lock
event      | transactionid
sum        | 682

出力されるカラム情報は以下になります。

event_type : 待機イベントの種別(pg_stat_activityビューのwait_event_type列の値が格納される)
event : 待機イベント名(pg_stat_activityビューのwait_event列と同じ値が格納される)
sum : 待機イベントが発生した回数

・確認観点

発生回数の多い待機イベント回数を確認
SQL遅延などの性能問題が発生した時間帯において、発生した回数が多い待機イベントを確認します。
発生回数の多い待機イベントに合わせた対処方法を検討します。次に対処例を記載します。
表 5.8 発生回数の多い待機イベント毎の対処方法
項番 発生回数の多い待機イベント 概要 対処例
1
WAL書き込み(WALWriteLock,WALWrite)にて発生する待機イベント
WALのディスクへの書き込みで待ちが発生しています。
wal_buffersパラメータの値を増加させる、もしくはWALの出力先ディスクをより高速なディスクに変更するなどの対処を検討します。
2
データファイルの読み書き(DataFileRead,DataFileWrite)にて発生するした待機イベント
テーブルやインデックスなどを構成するデータファイルの読み込みにて待機が発生しています。
DBサーバに搭載するメモリの増強やテーブルスペースを利用しディスクIOの負荷を分散させるなどの対処を検討します。
また、インデックスの定義漏れなどで意図せず大量にデータを読み込んでいる可能性もあります。
3
待機イベント(event_type列)の種類がLockの場合
実行中のSQLにてロック待ちが発生しています。
SQLのロック待ち状態を確認して下さい。
4
クライアントからのデータの読み書き(ClientRead,ClientWrite)に関連したイベント
クライアントからのデータの読み込み・書き込みにて待機が発生しています。
大量データの通信にて待ちが発生しているもしくはクライアントとDBサーバ間のネットワークで遅延が発生している可能性があります。
5
同期レプリカからの確認待ち(SyncRep)にてイベント
同期レプリケーション中に、レプリカからの確認にて待ちが発生しています。
同期レプリカやレプリケーションにて利用するネットワークにて障害が発生している可能性があります。
また、マスタで大量データの更新を行った場合に同期レプリカでのWAL書き込みや適用に時間がかかり、待ちが発生している可能性があります。

・参考情報

[25]pg_wait_sampling – sampling based statistics of wait events

6. ケーススタディ

6.1. ロングトランザクションによる性能トラブル

6.1.1. 概要

PostgreSQLは追記型のアーキテクチャを採用していますので、更新処理が行われる度に行レコード(タプル)が増えていきます。
不要となったタプルはVACUUM処理によって回収され、その領域は再利用されます。
このようにVACUUM処理が定期的に実行されることで、データベースは肥大化せずに安定動作を実現しています。

このVACUUM処理を阻害する要因となるのが、「ロングトランザクション」です。
ロングトランザクションとは、BEGINを発行してからCOMMITするまで、長時間かかっている処理を指します。
VACUUM処理を実行する際に不要領域の判定を行いますが、この判定は各トランザクションの可視性から判断されます。
つまり、ロングトランザクションが存在することで、不要となったタプルが不要領域と判断されずに、いつまでたっても
VACUUM処理で回収されなくなります。
このような状態で運用を続けますと、データベースが肥大化していき、性能トラブルを引き起こすトラブルに発展していきますので、
予めロングトランザクションが発生していないかを監視しておくことが必要となります。

下記に「ロングトランザクションによる性能トラブル」についての事例を記載します。

6.1.2. 性能トラブル内容

データベースを運用していたところ、しばらくは問題なく動作していましたが
いつ頃からか、処理遅延が頻発するようになりました。
発生した処理遅延は以下の通りです。

1. トランザクション処理数の低下
日中帯(9:00～17:00)にオンラインで実行されているトランザクションの処理数が減少しています。
正常時の遅延発生時のTPS値での比較

(正常期間)
tps = 773.078073

(処理遅延発生期間)
tps = 400.656880
2. 夜間帯(深夜0:00時頃)にバッチで実行されているSQLの遅延
夜間帯に実行されるSQLが遅延SQLとして、PostgreSQLのログファイルに出力されるようになりました。
なお、本システムではSQLの遅延の閾値を10秒としているため、「log_min_duration_statement = 10s」を指定し、
遅延が発生したSQLをPostgreSQLのログファイルに出力しています。

■ログ確認(遅延SQL)

[20XX-XX-XX XX:XX:XX.XXX JST][<ユーザ名>][<データベース名>][[<ホスト名]][<PID>][<セッションID>-<各セッションのログ行の番号>][0][00000]
psql LOG:  duration: 17374.466 ms  statement: SELECT bid ,count(*) FROM pgbench_accounts GROUP BY bid;

6.1.3. 調査・分析結果

■テーブルサイズ確認

処理時間の遅延が発生した場合、特定の処理で発生しているのか、または全体的に遅延しているかを確認します。
今回の事例では、全体的に処理時間が遅延しているとのことなので、まずはデータベースのテーブルサイズを確認します。
(テーブルサイズを確認するSQLは、こちら をご参照下さい。)
通常期間と比べ、テーブルサイズが増加していることが確認できます。
(正常期間)
     relname      | reltuples | tablesize
------------------+-----------+-----------
 pgbench_history  |    256897 | 15 MB
 pgbench_tellers  |      1000 | 128 kB
 pgbench_branches |       100 | 96 kB
 pgbench_accounts |     1e+07 | 1299 MB
(4 rows)

(処理遅延発生期間)
     relname      | reltuples | tablesize
------------------+-----------+-----------
 pgbench_history  |    975506 | 51 MB
 pgbench_tellers  |      1000 | 42 MB    ---レコード数は変化していないが、テーブルサイズが顕著に増加
 pgbench_branches |       100 | 34 MB    ---レコード数は変化していないが、テーブルサイズが顕著に増加
 pgbench_accounts |     1e+07 | 1407 MB
(4 rows)

■不要領域の確認

データベースおよびテーブルの肥大化が確認できましたら、それがレコード数増加によるものか、またはVACUUM処理(autovacuum含む)による
不要領域の回収で問題が発生しているかを確認します。
(テーブル毎の不要領域を確認するSQLは、こちら をご参照下さい。)
n_dead_tupが増加していることからVACUUM処理による不要領域の回収で問題が発生していることが確認できます。(※)
※テーブルサイズの20%不要領域が溜まったら、autovacuumが実行されることから、autovacuum処理が阻害されていると判断できます。
(処理遅延発生期間)
     relname      | n_live_tup | n_dead_tup | ratio
------------------+------------+------------+-------
 pgbench_branches |        100 |     984767 | 99.00
 pgbench_history  |     998339 |          0 |     0
 pgbench_accounts |   10000006 |     999295 |  9.00
 pgbench_tellers  |       1000 |     984779 | 99.00
(4 rows)

■稼動統計情報の確認

VACUUM処理による不要領域の回収で問題が発生していることから、ロングトランザクションが発生していると推測し、稼動統計情報を確認します。
稼動統計情報の中から、ロングトランザクションに該当する処理(stateが「idle in transaction」のまま、長時間トランザクションが閉じられていない処理)が
発生していないかを確認します。
(ロングトランザクションを確認SQLは、こちら をご参照下さい。)
ロングトランザクションが発生していた場合、queryから該当の処理がロングトランザクション化した原因を調査し、対処します。(※)
※アプリケーション側のコミット漏れ等
(処理遅延発生期間)
     :
-[ RECORD 7 ]---+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
pid             | 6763
wait_event_type | Client
wait_event      | ClientRead
state           | idle in transaction
duration        | 00:30:10.235
query           | INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (111111111, 1, 1, 0, CURRENT_TIMESTAMP);
     :

6.1.4. 性能トラブルの改善案

調査の結果、特定の処理がロングトランザクション化していることが性能トラブルの原因となっていることが確認できます。
一般的にロングトランザクション化する要因としてアプリケーション側のコミット漏れがあります。
このようにアプリケーション側に問題がある場合、改修までに時間が掛かることがあります。

運用時にこの性能トラブルを回避するには、以下のような方法があります。
1. PostgreSQLの設定ファイルで「idle_in_transaction_session_timeout (PostgreSQL 9.6～)」を任意の時間に設定し、設定ファイルの変更を反映(pg_ctl reload)
2. 対象のプロセスをpg_terminate_backendコマンドで終了

運用時でもこれらの方法で性能トラブルを回避することはできますが、あくまで暫定対策とし、アプリケーションの改修など根本的な改善策の実施をご検討ください。

6.1.5. 備考

PostgreSQLでは、削除されたレコード(=不要領域)を回収する際に他のトランザクションからの可視性を確認します。
よって、他のトランザクションの状態やトランザクション分離レベルによっては、VACUUM処理を阻害することになります。
今回の事象のようにトランザクションがVACUUM処理を阻害するケースを以下に示します。

リードコミッティド
・実行中のクエリ
・書き込みを行いアイドル状態になっているトランザクション
(書き込みを行っていないトランザクションであればVACUUM処理を阻害しません)

シリアライザブル
・実行中のクエリ
・読み込み、または書き込みを行いアイドル状態になっているトランザクション

6.2. ディスク性能の考慮漏れによる性能トラブル

6.2.1. 概要

PostgreSQLはコストベースオプティマイザを採用しており、SQL文と統計情報を元に選択可能な実行計画を列挙し、
各プランのコストを計算します。その中で最もコストの低い実行計画を選択します。
(コストと実行計画の詳細は、「PostgreSQLクエリ実行の基礎知識 ～Explainを読み解こう～」 にて
解説されていますので、参照して下さい。)

PostgreSQLのデフォルト設定では、seq_page_costパラメータ(シーケンシャルスキャンアクセスのコスト)は1、
random_page_costパラメータ(ランダムアクセスのコスト)は4に設定されています。
このデフォルト設定は、ランダムアクセスはシーケンシャルアクセスより、4倍コストが高い設定になっており、
ハードディスクにデータベースが格納された場合を想定し、設定されている値です。

しかし、SSDなどの高速なストレージを利用した場合には、ランダムアクセスは、シーケンシャルアクセスと比較して4倍も遅くはありません。
そのため、デフォルト設定では、ランダムアクセスの方がシーケンシャルアクセスより、
高速に結果を得られるにも関わらず、PostgreSQLがシーケンシャルアクセスを選択してしまい、
性能遅延(性能トラブル)が発生するケースがあります。

6.2.2. 性能トラブル内容

SSDをストレージに採用しているDBサーバにおいて、
SELECT文が遅延し、PostgreSQLログファイルに遅延SQLが出力されています。

■ ログの確認状況

今回例示しているPostgreSQLではSQLの遅延の閾値を3秒としているため、
「log_min_duration_statement = 3s」を指定し、遅延が発生したSQLをPostgreSQLのログファイルに出力しています。
LOG:  duration: 4229.749 ms  statement: SELECT * FROM sample_a JOIN sample_b ON sample_a.id2 = sample_b.bid2 WHERE sample_a.id1 = '0500000';
遅延が発生するSQLは、ログファイルから抜粋した以下です。
SELECT * FROM sample_a JOIN sample_b ON sample_a.id2 = sample_b.bid2 WHERE sample_a.id1 = '0500000';

■ テーブル定義

遅延が発生するSQLでは、sample_aテーブルとsample_bテーブルのテーブル結合を実施していますが、
大規模なテーブルため、必要なインデックスをそれぞれ定義しています。テーブルの定義は以下の通りです。
=# \d sample_a
               Table "public.sample_a"
     Column |       Type        | Collation | Nullable | Default
    --------+-------------------+-----------+----------+---------
     id1    | character varying |           |          |
     id2    | integer           |           |          |
     date   | date              |           |          |
    Indexes:
    "sample_a_idx" btree (id2, id1)

=# \d sample_b
                   Table "public.sample_b"
     Column |       Type        | Collation | Nullable | Default
     --------+-------------------+-----------+----------+---------
     bid2   | integer           |           | not null |
     name   | character varying |           |          |
     Indexes:
             "sample_b_pkey" PRIMARY KEY, btree (bid2)

6.2.3. 調査・分析結果

■ 実行計画の確認

遅延が発生したSQLの実行計画をEXPLAIN ANALYZEコマンドを用いて取得したところ、
以下のように各テーブルのスキャンにシーケンシャルスキャン(Seq Scan)が選択され、
結合にはハッシュ結合(Hash Join)が選択されていました。
また、PostgreSQLが予測した行数と、実際に取得した行数(rowsにて確認)に差がないため、統計情報の更新漏れ(ANALYZEが実行されいない)状況ではないことがわかりました。
=# EXPLAIN ANALYZE SELECT * FROM sample_a JOIN sample_b ON sample_a.id2 = sample_b.bid2 WHERE sample_a.id1 = '0500000';
                                                       QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------
 Hash Join  (cost=187056.15..570987.47 rows=460327 width=53) (actual time=1005.652..5342.292 rows=500000 loops=1)
   Hash Cond: (sample_b.bid2 = sample_a.id2)
   ->  Seq Scan on sample_b  (cost=0.00..183332.58 rows=9999858 width=37) (actual time=0.009..1335.758 rows=10000000 loops=1)
   ->  Hash  (cost=179054.03..179054.03 rows=460330 width=16) (actual time=1003.073..1003.073 rows=500000 loops=1)
         Buckets: 131072  Batches: 8  Memory Usage: 3953kB
         ->  Seq Scan on sample_a  (cost=0.00..179054.03 rows=460330 width=16) (actual time=0.012..905.575 rows=500000 loops=1)
               Filter: ((id1)::text = '0500000'::text)
               Rows Removed by Filter: 9500000
 Planning time: 0.260 ms
 Execution time: 5379.779 ms
(10 rows)

■ 遅延しているSQLで参照するレコード

遅延しているSQLで取得するレコードが全レコードの内、どの程度の割合で存在するのかを確認しました。
まずは各テーブルに格納されたレコード数を確認しました。いずれのテーブルでもおおよそ1,000万件のレコードが格納されていることがわかります。
(PostgreSQLの統計情報を用いた確認)
=# SELECT relname,n_live_tup from pg_stat_user_tables WHERE relname IN ('sample_a','sample_b');
 relname  | n_live_tup
----------+------------
 sample_a |    9999922
 sample_b |    9999858
(2 rows)

(実際のレコードを取得して確認)
=# SELECT count(*) FROM sample_a ;
  count
----------
 10000000
(1 row)
=# SELECT count(*) FROM sample_b ;
  count
----------
 10000000
(1 row)
問題となるSQLでWHERE句の条件で指定されている、「sample_a.id1 = ‘0500000’」に合致するレコードが
どの程度の割合で存在するのかをか確認しました。
以下SQLの結果より、「0500000」の値を持つレコードは、「0.0460333」(おおよそ4.6%)の割合で存在することがわかりました。
(PostgreSQLの統計情報を用いた確認)
=# SELECT * FROM pg_stats WHERE tablename = 'sample_a' AND attname = 'id1';
-[ RECORD 1 ]----------+--------------------------------------------
schemaname             | public
tablename              | sample_a
attname                | id1
inherited              | f
null_frac              | 0
avg_width              | 8
n_distinct             | 5
most_common_vals       | {[省略],0500000}
most_common_freqs      | {[省略],0.0460333}
histogram_bounds       |
correlation            | 1
most_common_elems      |
most_common_elem_freqs |
elem_count_histogram   |

(実際のレコードを取得して確認)
=# SELECT count(*) as record_num ,count(*)/10000000::FLOAT * 100 AS percent FROM sample_a WHERE id1 = '0500000';
 record_num | percent
------------+---------
     500000 |       5  -- id1 = '0500000';を満たす行数は500,000件存在し、全体の5%
(1 row)

■ コストパラメータの変更

sample_aテーブル全体のレコード内、5%のレコードを取得するSQLであるため、
シーケンシャルスキャンよりインデックスを利用して実行した方が高速に処理される可能性があると考え、
試しにrandom_page_costパラメータ(ランダムアクセスのコスト)を4から2に変更し、実行しました。
random_page_costを2変更した結果、SQL実行時間が、5379.779 ms⇒ 886.744 msに改善しました。
SQLの実行計画も、シーケンシャルスキャンから、インデックススキャンに変わり、マージ結合が実施されるようになりました。
=# SET random_page_cost TO 2;
=# EXPLAIN ANALYZE SELECT * FROM sample_a JOIN sample_b ON sample_a.id2 = sample_b.bid2 WHERE sample_a.id1 = '0500000';
                                                               QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
 Merge Join  (cost=5.88..524232.63 rows=460327 width=53) (actual time=0.027..849.794 rows=500000 loops=1)
   Merge Cond: (sample_a.id2 = sample_b.bid2)
   ->  Index Scan using sample_a_idx on sample_a  (cost=0.43..205313.90 rows=460330 width=16) (actual time=0.012..522.793 rows=500000 loops=1)
         Index Cond: ((id1)::text = '0500000'::text)
   ->  Index Scan using sample_b_pkey on sample_b  (cost=0.43..288175.30 rows=9999858 width=37) (actual time=0.009..118.594 rows=500000 loops=1)
 Planning time: 0.835 ms
 Execution time: 886.744 ms
(7 rows)

6.2.4. 性能トラブルの改善案

SSDなどの従来のハードディスクと比較すると、ランダムスキャンが高速に実行可能なストレージ装置を利用する場合においては、
random_page_costパラメータをseq_page_costパラメータに近い値に設定すると、SQLの実行でランダムスキャン(インデックススキャン)が
選択され、性能が改善したとの報告がされています。

[翻訳] たった一つの設定変更が如何にしてクエリのパフォーマンスを50倍も改善したか
（How a single PostgreSQL config change improved slow query performance by 50x）
http://pgsqldeepdive.blogspot.jp/2017/11/50-how-single-postgresql-config-change.html

本事例で紹介したSQLでも、random_page_costパラメータを1に近づけることで、SQLの性能を改善することが確認できました。

6.2.5. 備考

SSDの環境において、インデックススキャンとシーケンシャルスキャンの性能差を確認するため、簡単な試験を実施しました。
pgbenchで生成した、10,000,000(1,000万件)のデータが格納されるpgbench_accountsテーブルを利用しています。

SQLで取得するpgbench_accountsテーブルのレコードの割合を1～100%(1%ずつ増加)変化させて、下記トランザクションの実行時間を測定しました。 また、下記トランザクションを実行する前に下記コマンドでキャッシュの破棄を実行しています。

(シーケンシャルスキャンで実行するSQL)
=# set enable_indexscan to 'off';
=# set enable_bitmapscan to 'off';
=# SELECT * FROM pgbench_accounts WHERE aid >= 1 and aid <= 100000 * [レコードを取得する割合(1～100に変化させる)]

(インデックススキャンで実行するSQL)
=# set enable_seqscan to 'off';
=# set enable_bitmapscan to 'off';
=# SELECT * FROM pgbench_accounts WHERE aid >= 1 and aid <= 100000 * [レコードを取得する割合(1～100に変化させる)]

(キャッシュを破棄するために実行したコマンド)
$ pg_ctl restart
$ echo 1 > /proc/sys/vm/drop_caches
結果は以下のようになり、インデックススキャン(ランダムスキャン)の実行時間は、
テーブル内のすべてのレコードを取得する際に、1.16倍となりました。
インデックススキャン : 16000.297ms
シーケンシャルスキャン : 13688.574
インデックススキャンはシーケンシャルスキャンと比較すると、
インデックス分読み込むサイズが大きいにも関わらず、1.16倍の差のみのため、
random_page_costを1に近い値に設定する設定に大きな問題はないと考えます。
SSDにおけるシーケンシャルスキャンとインデックススキャンの性能比較

6.3. 適切でない実行計画が選択されてしまうことによる性能トラブル

6.3.1. 概要

ディスク性能の考慮漏れによる性能トラブル で記載していますがPostgreSQLは統計情報をもとに実行計画のコストを推定し、 最もコストの低い実行計画に基づいてクエリを実行します。

そのため統計情報とデータベース内のデータの実態に剥離があった場合は適切でない実行計画が選択されてしまい、 性能劣化(性能トラブル)が発生してしまうケースがあります。

下記に「適切でない実行計画が選択されてしまった場合に発生する性能トラブル」の事例を記載します。 ※事例内のオブジェクト名や数値については架空のものとして記載しております。

6.3.2. 性能トラブル内容

夜間に大規模な業務データに対し集計処理をバッチで実施するシステムを構築、運用していましたが、 運用開始後データが蓄積/更新されていくにつれて夜間のバッチ処理が遅延し、当初の想定時間内に終わらなくなってきました。

このままではいつか、翌営業日までに終わらなくなるかもしれません。

6.3.3. 調査・分析結果

データベース性能に影響を与える要素 の記載内容をもとに、 バッチ処理内のSQLの実行状況(ロックウェイト、一時ファイル、スロークエリ、explain)からボトルネックを特定していきます。

log_min_duration_statementを設定し、以下のスロークエリを特定しました。

LOG: duration: 14000123.456 ms statement: select public.func_sample();

次に当該クエリの実行計画を確認しようとしましたが、このクエリは関数が用いられており、 通常のEXPLAINでは関数内で実行されるSQLの実行計画を取得することができません。

そこで、一定時間内に実行された処理の結果 でも紹介しているauto_explainをインストール、設定します。 ANALYZEの結果も取得することと、関数内のSQL文の実行計画を取得するため以下の設定を施します。

SET auto_explain.log_analyze = true;           --EXPLAIN ANALYZEの結果を取得する。
SET auto_explain.log_nested_statements = true; --関数内のSQL文の実行計画も取得する。

そうして実行計画を確認したところ、以下のような結果が判明しました。


適切でないジョイン方式が選択されていた

構築時の評価、当初の想定では当該のクエリは効率的なハッシュジョインとなるべきでしたが、 マージジョインが選択されてしまっていました。

Merge Join  (cost=592815.42..8795552.29 rows=189878 width=669) (actual time=59000.961..13739668.541 rows=292192 loops=1)

インデックススキャンの時間がクエリ全体の実行時間をほぼ占めていた

test_idxインデックスのスキャン時間(13704s)がほぼクエリ全体の実行時間(14000s)となっていました

Index Scan using test_idx on sample_test t  (cost=0.00..7978601.06 rows=4237321 width=669) (actual time=13.852..13704413.467 rows=4314638 loops=1)

当該のクエリはマージジョインが選択されていましたが、マージジョインがソート済みの結果に基づいて処理を行うために、 ソート済みが保証されるtest_idxインデックスを利用したと考えられます。

6.3.4. 実施対応策

当該のクエリはハッシュジョインが効率的と想定しているため、 当該のクエリを実行する前に、enable_mergejoinパラメータをoffに設定することでハッシュジョインを選択させるようにしました。

SET enable_mergejoin TO OFF;

クエリの実行後はDEFAULTに戻しておきます

SET enable_mergejoin TO DEFAULT;

6.3.5. その後の展開

ハッシュジョインが選択されるようになり実行時間は短縮されましたが、 しばらく経った後にまた実行時間の遅延が見受けられるようになりました。

auto_explainにて再度実行計画のANALYZE結果と、テーブルの状況を確認したところ、 ハッシュジョインにおけるハッシュ作成対象テーブルについて、よりデータ件数が多いテーブルが選択されていたため非効率な走査になっていました。

Hash Join  (cost=1513012.17..8320833.14 rows=490606 width=669) (actual time=801456.867..1626321.178 rows=298112 loops=1)
   Hash Cond: (((testA_small.tenant_id)::text = (t.tenant_id)::text) AND ((testA_small.member_id)::text = (t.member_id)::text) AND
   (testA_small.use_date = t.use_date) AND ((testA_small.use_type)::text = (t.use_type)::text) AND
   ((testA_small.data_type)::text = (t.data_type)::text) AND ((testA_small.note)::text = (t.note)::text))
   ->  Seq Scan on testA_small  (cost=0.00..6054.33 rows=295933 width=14) (actual time=3.931..1941.207 rows=298112 loops=1)
   ->  Hash  (cost=745488.05..745488.05 rows=4356205 width=669) (actual time=790818.816..795818.816 rows=4325556 loops=1)
         Buckets: 1024  Batches: 16384  Memory Usage: 396kB
         ->  Seq Scan on testB_big t  (cost=0.00..725488.05 rows=4356205 width=669) (actual time=0.022..238413.991 rows=4325556 loops=1)
 Total runtime: 1626401.249 ms

・推奨されるハッシュ作成対象であり件数の少ないテーブル: testA_small
・今回のハッシュ作成対象であり件数の多いテーブル: testB_big

ハッシュ対象テーブルの選択についてはPostgerSQLのプランナが対象テーブルのデータの特徴などに基づいて決定するため、 統計情報が持つデータ件数と実際のデータ件数との間にズレがあったからと考えられます。

VACUUM ANALYZEを実施し統計情報を最新化すると適切なテーブルが選択されるようになったので、 手順としてANALYZEの定期実行を組み込むようにし、最適な実行計画が策定されるように改善させました。

6.3.6. 備考

本番運用に入ると実データの蓄積傾向により事前検証では予想もしなかったネックが発生します。 本件は統計情報と実態の剥離が発生したことにより実行計画が正しく策定されなかったことがトラブルの原因となりましたが、 設計/構築時の評価と運用開始後のギャップに備えるためにも以下のような対策を事前に検討しておくことを推奨いたします。

  • auto_explainを組み込んで解析を容易にしておく
  • 統計情報の最新化のため定期的なVACUUM ANALYZE実施を手順に組み込む
  • 実行計画制御のため、pg_hint_planやpg_dbms_statsを後から組み込める余地を残しておく

6.4. インデックスの定義漏れによる性能トラブル

6.4.1. 概要

一般的にインデックスを使用することで、参照SQLの性能を向上させることが可能です。 参照SQLの性能向上に必要なインデックスについては物理設計や性能試験などで設計が必要ですが、考慮不足などにより定義漏れが発生することがあります。 インデックスの定義漏れはテーブルのレコード数が少ない状態では影響が小さいですが、レコードが次第に多くなり、後々性能トラブルを引き起こすことがあります。

このような場合、テーブル設計書等でインデックスの定義漏れがないかを確認し、インデックス定義が漏れている場合は、インデックス作成などの対処が必要となります。 また、新たにインデックスを作成することで他のSQL(更新処理など)にどの程度影響があるかなど修正に伴う影響についての確認が必要となります。

下記に「インデックスの定義漏れによる性能トラブル」についての事例を記載します。

6.4.2. 性能トラブル内容

データベースを運用していたところ、テーブルレコードの増加に伴い、参照SQLの処理遅延が発生するようになりました。 これらの参照SQLはPostgreSQLログファイルに遅延SQLとして出力されています。

■ ログの確認状況

今回例示ではSQL遅延の閾値を3秒としているため、「log_min_duration_statement = 3s」に指定し、遅延が発生したSQLをPostgreSQLのログファイルに出力しています。

LOG:  duration: 24207.607 ms  statement: EXPLAIN ANALYZE SELECT a.aid,a.abalance,b.bbalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.bid = 90 ORDER BY a.abalance DESC LIMIT 10;

遅延が発生するSQLは、ログファイルから抜粋した以下です。

EXPLAIN ANALYZE SELECT a.aid,a.abalance,b.bbalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.bid = 90 ORDER BY a.abalance DESC LIMIT 10;

■ テーブル定義

遅延が発生するSQLでは、pgbench_accountsテーブルとpgbench_branchesテーブルのテーブル結合を行っています。 テーブルの定義は以下の通りです。

=# \d pgbench_accounts
                テーブル "public.pgbench_accounts"
    列    |      型       | 照合順序 | Null 値を許容 | デフォルト
----------+---------------+----------+---------------+------------
 aid      | integer       |          | not null      |
 bid      | integer       |          |               |
 abalance | integer       |          |               |
 filler   | character(84) |          |               |
インデックス:
    "pgbench_accounts_pkey" PRIMARY KEY, btree (aid)

=# \d pgbench_branches
                テーブル "public.pgbench_branches"
    列    |      型       | 照合順序 | Null 値を許容 | デフォルト
----------+---------------+----------+---------------+------------
 bid      | integer       |          | not null      |
 bbalance | integer       |          |               |
 filler   | character(88) |          |               |
インデックス:
    "pgbench_branches_pkey" PRIMARY KEY, btree (bid)

6.4.3. 調査・分析結果

■ 実行計画の確認

遅延が発生しているSQLの実行計画をEXPLAIN ANALYZEコマンドを用いて取得したところ、pgbench_accountsテーブルへのシーケンシャルスキャン(Seq Scan)が選択されており、実際にこの処理に時間(actual time)が掛かっておりました。 また、Seq Scanにてpgbench_accountsテーブルのレコードを取得した後、Filterにて多くのレコード(29,966,667行)を除外されています。 上記結果から遅延したSQLに必要なpgbench_accountsテーブルのインデックス定義が漏れている可能性が高いです。

=# EXPLAIN ANALYZE SELECT a.aid,a.abalance,b.bbalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.bid = 90 ORDER BY a.abalance DESC LIMIT 10;
                                                                            QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=1957951.40..1957951.42 rows=10 width=12) (actual time=24117.598..24119.773 rows=10 loops=1)
   ->  Sort  (cost=1957951.40..1958194.33 rows=97173 width=12) (actual time=24117.594..24117.595 rows=10 loops=1)
         Sort Key: a.abalance DESC
         Sort Method: top-N heapsort  Memory: 25kB
         ->  Nested Loop  (cost=1000.27..1955851.52 rows=97173 width=12) (actual time=2698.988..24086.384 rows=100000 loops=1)
               ->  Index Scan using pgbench_branches_pkey on pgbench_branches b  (cost=0.28..2.49 rows=1 width=8) (actual time=0.078..0.080 rows=1 loops=1)
                     Index Cond: (bid = 90)
               ->  Gather  (cost=1000.00..1954877.30 rows=97173 width=12) (actual time=2698.903..24063.367 rows=100000 loops=1)
                     Workers Planned: 2
                     Workers Launched: 2
                     ->  Parallel Seq Scan on pgbench_accounts a  (cost=0.00..1944160.00 rows=40489 width=12) (actual time=2688.060..24044.359 rows=33333 loops=3)
                           Filter: (bid = 90)
                           Rows Removed by Filter: 29966667  --- Seq Scanにてレコードを取得した後、Filter(bid = 90)にて多くのレコード(29,966,667行)を除外している
 Planning Time: 0.432 ms
 Execution Time: 24119.856 ms
(15 行)

■ 該当のテーブルにインデックスを作成

今回のケースはインデックスの貼り忘れであるため、SQLの検索条件(WHERE a.bid = 90)に指定されたbid列にインデックスを作成することで性能を改善することができます。 上記の対処によりSQL実行時間が24119.856 ms->41.204 msに改善されました。

 =# CREATE INDEX pgbench_accounts_bid_idx ON pgbench_accounts(bid);
 =# EXPLAIN ANALYZE SELECT a.aid,a.abalance,b.bbalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.bid = 90 ORDER BY a.abalance DESC LIMIT 10;
                                                                                 QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=6675.75..6675.77 rows=10 width=12) (actual time=41.129..41.131 rows=10 loops=1)
   ->  Sort  (cost=6675.75..6918.68 rows=97173 width=12) (actual time=41.126..41.126 rows=10 loops=1)
         Sort Key: a.abalance DESC
         Sort Method: top-N heapsort  Memory: 25kB
         ->  Nested Loop  (cost=0.57..4575.88 rows=97173 width=12) (actual time=0.123..29.516 rows=100000 loops=1)
               ->  Seq Scan on pgbench_branches b  (cost=0.00..15.25 rows=1 width=8) (actual time=0.066..0.108 rows=1 loops=1)
                     Filter: (bid = 90)
                     Rows Removed by Filter: 899
               ->  Index Scan using pgbench_accounts_bid_idx on pgbench_accounts a  (cost=0.57..3588.90 rows=97173 width=12) (actual time=0.048..18.980 rows=100000 loops=1)
                     Index Cond: (bid = 90)
 Planning Time: 0.454 ms
 Execution Time: 41.204 ms
(12 行)

6.4.4. 性能トラブルの改善案

EXPLAIN ANALYZEコマンドの取得結果にて、本事例のようにシーケンシャルスキャン後にFilterにて多くのレコードが除外されている場合は(Rows Removed by Filter: 29966667の箇所)、該当SQLにて必要なインデックスが定義されていない可能性があります。 本事例ではSQLに必要なインデックスを定義することで性能が劇的に改善することが確認できました。

データ量が少ない状態で、SQLの実行時間を判断すると、運用開始後のデータ増加で性能トラブルとなる場合が御座いますのでご注意願います。 また、インデックスを追加定義したテーブルに対して、更新・参照を行っているSQLについては、インデックス定義による性能影響を確認する必要が御座います。

6.5. インデックスの肥大化による性能トラブル

6.5.1. 概要

B-treeインデックス(以降、インデックス)に格納されるデータはページと呼ばれる領域(デフォルト:8192B)に格納されます。 ページ内のほとんどのデータが削除された場合でも、一部のデータがページに残る場合は、ページは割り当てられたまま残ります。 ページ内のほとんどのデータを削除するような操作が繰り替えし実行されると、1ページに格納されるデータ数が少なくなり、インデックスが肥大化した状態になります。 インデックスが肥大化した場合、無駄なディスク領域が必要となるだけではなく、性能トラブルを引き起こす要因にもなります。

このような場合、インデックスの再作成が必要となりますが、インデックスの再作成の方法の一つである「REINDEX」は、処理中に該当インデックスに排他ロックを取得しますので、インデックスを利用した参照処理とテーブルの更新処理はロック待ちになります。 「REINDEX」を実行する他にインデックスの再作成方法として、「CREATE INDEX CONCURRENTLY」にて新しいインデックスを作成した後に古いインデックスを削除する方法があります。

下記に「インデックスの肥大化による性能トラブル」についての事例を記載します。

6.5.2. 性能トラブル内容

データベースを運用していたところ、データの増加に伴い、参照SQLの処理遅延が発生するようになりました。 これらの参照SQLはPostgreSQLログファイルに遅延SQLとして出力されています。

■ ログの確認状況

今回例示ではSQLの処理時間が30秒以上掛かってしまった場合、再処理を行う必要がでてくるため、問題視される仕様となります。 再処理では、短時間で処理が完了している状態となります。 SQL遅延の閾値を3秒としているため、「log_min_duration_statement = 3s」に指定し、遅延が発生したSQLをPostgreSQLのログファイルに出力しています。

LOG:  duration: 39359.443 ms  statement: SELECT a.aid, a.bid, a.abalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.abalance BETWEEN -10 AND 10 ORDER BY a.abalance

遅延が発生するSQLは、ログファイルから抜粋した以下です。

SELECT a.aid, a.bid, a.abalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.abalance BETWEEN -10 AND 10 ORDER BY a.abalance

■ テーブル定義

遅延が発生するSQLでは、pgbench_accountsテーブルとpgbench_branchesテーブルのテーブル結合を行っています。 結合条件や絞り込みを行っているカラムに対してインデックスが定義されております。 テーブルの定義は以下の通りです。

=# \d pgbench_accounts
                テーブル "public.pgbench_accounts"
    列    |      型       | 照合順序 | Null 値を許容 | デフォルト
----------+---------------+----------+---------------+------------
 aid      | integer       |          | not null      |
 bid      | integer       |          |               |
 abalance | integer       |          |               |
 filler   | character(84) |          |               |
インデックス:
    "pgbench_accounts_pkey" PRIMARY KEY, btree (aid)
    "pgbench_accounts_abalance_idx" btree (abalance)

=# \d+
                           リレーション一覧
 スキーマ |       名前       |    型    |  所有者  |   サイズ   | 説明
----------+------------------+----------+----------+------------+------
 public   | pgbench_accounts | テーブル | postgres | 1310 MB    |
 public   | pgbench_branches | テーブル | postgres | 1704 kB    |
 public   | pgbench_history  | テーブル | postgres | 42 MB      |
 public   | pgbench_tellers  | テーブル | postgres | 1824 kB    |
(4 行)

=# \di+
                                           リレーション一覧
 スキーマ |             名前              |      型      |  所有者  |     テーブル     | サイズ | 説明
----------+-------------------------------+--------------+----------+------------------+--------+------
 public   | pgbench_accounts_abalance_idx | インデックス | postgres | pgbench_accounts | 922 MB |
 public   | pgbench_accounts_pkey         | インデックス | postgres | pgbench_accounts | 428 MB |
 public   | pgbench_branches_pkey         | インデックス | postgres | pgbench_branches | 48 kB  |
 public   | pgbench_tellers_pkey          | インデックス | postgres | pgbench_tellers  | 208 kB |
(4 行)

=# \d pgbench_branches
                テーブル "public.pgbench_branches"
    列    |      型       | 照合順序 | Null 値を許容 | デフォルト
----------+---------------+----------+---------------+------------
 bid      | integer       |          | not null      |
 bbalance | integer       |          |               |
 filler   | character(88) |          |               |
インデックス:
    "pgbench_branches_pkey" PRIMARY KEY, btree (bid)

■ 実行計画の確認

遅延が発生しているSQLの実行計画をEXPLAIN ANALYZEコマンドを用いて取得したところ、全体の処理時間(actual time)の中で、pgbench_accounts_abalance_idxインデックスを用いたBitmap Index Scanやpgbench_accountsテーブルのBitmap Heap Scan処理に時間が掛かっていることが確認できます。

=# EXPLAIN ANALYZE SELECT a.aid, a.bid, a.abalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.abalance BETWEEN -10 AND 10 ORDER BY a.abalance;
                                                                              QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=257920.19..258243.70 rows=129406 width=12) (actual time=39249.571..39338.562 rows=132062 loops=1)
   Sort Key: a.abalance
   Sort Method: external merge  Disk: 2856kB
   ->  Hash Join  (cost=5931.99..245036.62 rows=129406 width=12) (actual time=8040.305..38902.386 rows=132062 loops=1)
         Hash Cond: (a.bid = b.bid)
         ->  Bitmap Heap Scan on pgbench_accounts a  (cost=5910.97..244661.51 rows=129406 width=12) (actual time=8031.934..38435.504 rows=132062 loops=1)
               Recheck Cond: ((abalance >= '-10'::integer) AND (abalance <= 10))
               Rows Removed by Index Recheck: 1953962
               Heap Blocks: exact=57832 lossy=33523
               ->  Bitmap Index Scan on pgbench_accounts_abalance_idx  (cost=0.00..5878.62 rows=129406 width=0) (actual time=7979.119..7979.120 rows=132062 loops=1)
                     Index Cond: ((abalance >= '-10'::integer) AND (abalance <= 10))
         ->  Hash  (cost=19.77..19.77 rows=100 width=4) (actual time=8.299..8.300 rows=100 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 12kB
               ->  Index Only Scan using pgbench_branches_pkey on pgbench_branches b  (cost=0.27..19.77 rows=100 width=4) (actual time=7.947..8.137 rows=100 loops=1)
                     Heap Fetches: 0
 Planning Time: 209.659 ms
 Execution Time: 39413.573 ms
(17 行)

■ タプルレベルでの統計情報確認

実行計画から、全体的に処理に時間が掛かっていることが確認できました。 これは、関連するテーブルやインデックスの読み込みでディスクアクセスが発生していることが考えられます。 まずは該当するテーブルやインデックスに対して、タプルレベルで統計情報を取得し、改善事項を調査します。 ※タプルレベルでの統計情報を取得するにはpgstattupleモジュールを導入する必要があります。

=# \x
=# SELECT * FROM pgstattuple_approx('pgbench_accounts');
-[ RECORD 1 ]--------+-----------------
table_len            | 1372872704
scanned_percent      | 0
approx_tuple_count   | 10000006
approx_tuple_len     | 1344533504
approx_tuple_percent | 97.9357736578613
dead_tuple_count     | 0
dead_tuple_len       | 0
dead_tuple_percent   | 0
approx_free_space    | 28339200
approx_free_percent  | 2.06422634213871

=# SELECT * FROM pgstatindex('pgbench_accounts_abalance_idx');
-[ RECORD 1 ]------+----------
version            | 3
tree_level         | 3
index_size         | 967122944 -- table_lenの割に大きい
root_block_no      | 114654
internal_pages     | 423
leaf_pages         | 117211
empty_pages        | 0
deleted_pages      | 422
avg_leaf_density   | 21.23 -- avg_leaf_densityの値が低い
leaf_fragmentation | 61.15

■ 「CREATE INDEX CONCURRENTLY」を実行し、インデックスを再作成

タプルレベルでの統計情報から対象のインデックスはテーブルサイズの70%程度のサイズにも関わらず、リーフページの密度が低い状態であることから肥大化している状態だと判断できますので、インデックスを再作成します。 この時、REINDEXを実行しますとサービスに影響がありますので、「CREATE INDEX CONCURRENTLY」を実行する方法でインデックスの再作成を行います。

=# CREATE INDEX CONCURRENTLY pgbench_accounts_abalance_idx_new ON pgbench_accounts(abalance);
=# BEGIN;
=# DROP INDEX pgbench_accounts_abalance_idx;
=# ALTER INDEX pgbench_accounts_abalance_idx_new RENAME TO pgbench_accounts_abalance_idx;
=# COMMIT;

対象のインデックスの再作成を行うことで肥大化が解消されましたので、再度遅延していたSQLを実行したところ、SQL実行時間が39413.573 ms->34905.916 msに改善されました。 対象のインデックスのコスト値を比較しますと、5878.62->2492.30と半分以下となっておりますので、CPUが読み込むページ数が減少したことで性能改善したものと推測しております。

=# EXPLAIN ANALYZE SELECT a.aid, a.bid, a.abalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.abalance BETWEEN -10 AND 10 ORDER BY a.abalance;
                                                                            QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=257716.32..258058.04 rows=136687 width=12) (actual time=34717.811..34824.527 rows=132062 loops=1)
   Sort Key: a.abalance
   Sort Method: external merge  Disk: 2856kB
   ->  Hash Join  (cost=2529.73..244052.57 rows=136687 width=12) (actual time=184.928..34347.245 rows=132062 loops=1)
         Hash Cond: (a.bid = b.bid)
         ->  Bitmap Heap Scan on pgbench_accounts a  (cost=2526.48..243675.30 rows=136687 width=12) (actual time=184.573..33855.856 rows=132062 loops=1)
               Recheck Cond: ((abalance >= '-10'::integer) AND (abalance <= 10))
               Rows Removed by Index Recheck: 1995080
               Heap Blocks: exact=57090 lossy=33517
               ->  Bitmap Index Scan on pgbench_accounts_abalance_idx  (cost=0.00..2492.30 rows=136687 width=0) (actual time=150.290..150.291 rows=132062 loops=1)
                     Index Cond: ((abalance >= '-10'::integer) AND (abalance <= 10))
         ->  Hash  (cost=2.00..2.00 rows=100 width=4) (actual time=0.287..0.287 rows=100 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 12kB
               ->  Seq Scan on pgbench_branches b  (cost=0.00..2.00 rows=100 width=4) (actual time=0.022..0.149 rows=100 loops=1)
 Planning Time: 222.962 ms
 Execution Time: 34905.916 ms
(16 行)

=# SELECT * FROM pgstatindex('pgbench_accounts_abalance_idx');
-[ RECORD 1 ]------+----------
version            | 3
tree_level         | 2
index_size         | 224641024
root_block_no      | 290
internal_pages     | 98
leaf_pages         | 27323
empty_pages        | 0
deleted_pages      | 0
avg_leaf_density   | 90.09
leaf_fragmentation | 0

インデックスの肥大化を解消しましたが、大幅な性能改善は見られませんでした。 そこで、該当の処理前にテーブルやインデックスをメモリ上に展開しておくためにアプリケーション側にてpg_prewarm関数を行うことで大幅な性能改善を実現致しました。 ※処理時間は34905.916 ms->2080.529 msに改善されています。

=# SELECT pg_prewarm('pgbench_accounts');
=# SELECT pg_prewarm('pgbench_accounts_abalance_idx');
=# EXPLAIN ANALYZE SELECT a.aid, a.bid, a.abalance FROM pgbench_accounts AS a INNER JOIN pgbench_branches AS b ON b.bid = a.bid WHERE a.abalance BETWEEN -10 AND 10 ORDER BY a.abalance;
                                                                           QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=257716.32..258058.04 rows=136687 width=12) (actual time=1936.789..2013.691 rows=132062 loops=1)
   Sort Key: a.abalance
   Sort Method: external merge  Disk: 2856kB
   ->  Hash Join  (cost=2529.73..244052.57 rows=136687 width=12) (actual time=126.453..1807.662 rows=132062 loops=1)
         Hash Cond: (a.bid = b.bid)
         ->  Bitmap Heap Scan on pgbench_accounts a  (cost=2526.48..243675.30 rows=136687 width=12) (actual time=126.123..1612.605 rows=132062 loops=1)
               Recheck Cond: ((abalance >= '-10'::integer) AND (abalance <= 10))
               Rows Removed by Index Recheck: 1995080
               Heap Blocks: exact=57090 lossy=33517
               ->  Bitmap Index Scan on pgbench_accounts_abalance_idx  (cost=0.00..2492.30 rows=136687 width=0) (actual time=99.474..99.474 rows=132062 loops=1)
                     Index Cond: ((abalance >= '-10'::integer) AND (abalance <= 10))
         ->  Hash  (cost=2.00..2.00 rows=100 width=4) (actual time=0.263..0.264 rows=100 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 12kB
               ->  Seq Scan on pgbench_branches b  (cost=0.00..2.00 rows=100 width=4) (actual time=0.022..0.119 rows=100 loops=1)
 Planning Time: 100.851 ms
 Execution Time: 2080.529 ms
(16 行)

6.5.3. 性能トラブルの改善案

今回の事例では、インデックスの肥大化を解消しましたが大幅な性能改善は見受けられませんでした。 しかしながら、システムを長期間運用していく中で、テーブルやインデックスの肥大化は避けては通れない問題となります。 性能トラブルを事前に検知するためにも更新頻度の高いシステムであれば、定期的にテーブルやインデックスの状態監視を行うことを推奨致します。 これらの情報を監視項目に取り入れ、メンテナンス時間などに定期的にテーブルやインデックスの再構築・再作成を行うことで、性能トラブルの発生を抑止することができます。

テーブル断片化 インデックス断片化

6.6. 複合インデックスの定義順誤りによる性能トラブル

6.6.1. 概要

PostgreSQLでは、B-tree、GiST、GINおよびBRINインデックス型での複合インデックスをサポートしており、複数列に対するB-treeインデックスはインデックス対象列の任意の部分集合を含む問い合わせ条件で使用することができます。

複合インデックスを使用する際には、先頭側の(左側)列に制約がある場合に最も効率的になります。 また、先頭側の列よりも右側の列に対する制約は、このインデックス内から検査されますが、スキャンされるインデックスの範囲を減らしませんので、必要以上にコストが掛かることになり、効率が悪くなります。 これらの場合、プランナはインデックスの使用よりもシーケンシャルテーブルスキャンが選択されることになります。

下記に「複合インデックスの定義順誤りによる性能トラブル」についての事例を記載します。

6.6.2. 性能トラブル内容

データベースを運用していたところ、データの増加に伴い、参照SQLの処理遅延が発生するようになりました。 これらの参照SQLはPostgreSQLログファイルに遅延SQLとして出力されています。

■ ログの確認状況

今回例示ではSQL遅延の閾値を3秒としているため、「log_min_duration_statement = 3s」に指定し、遅延が発生したSQLをPostgreSQLのログファイルに出力しています。

LOG:  duration: 5335.203 ms  statement: SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "都道府県" IN ('東京都', '神奈川県', '埼玉県', '千葉県') AND "事業所名" LIKE '学校法人%';

遅延が発生するSQLは、ログファイルから抜粋した以下です。

SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "都道府県" IN ('東京都', '神奈川県', '埼玉県', '千葉県') AND "事業所名" LIKE '学校法人%';

■ テーブル定義

遅延が発生するSQLでは、”全国住所”テーブルの”都道府県”と”事業所名”カラムを使用してデータの絞り込みを実施しています。 対象のカラムに対して複合インデックスが定義されています。テーブルの定義は以下の通りです。

=# \d "全国住所"
                        テーブル "public.全国住所"
      列      |        型         | 照合順序 | Null 値を許容 | デフォルト
--------------+-------------------+----------+---------------+------------
 住所CD       | character varying |          |               |
 都道府県CD   | character varying |          |               |
 市区町村CD   | character varying |          |               |
 町域CD       | character varying |          |               |
 郵便番号     | character varying |          |               |
 事業所フラグ | boolean           |          |               |
 廃止フラグ   | boolean           |          |               |
 都道府県     | character varying |          |               |
 都道府県カナ | character varying |          |               |
 市区町村     | character varying |          |               |
 市区町村カナ | character varying |          |               |
 町域         | character varying |          |               |
 町域カナ     | character varying |          |               |
 町域補足     | character varying |          |               |
 京都通り名   | character varying |          |               |
 字丁目       | character varying |          |               |
 字丁目カナ   | character varying |          |               |
 補足         | text              |          |               |
 事業所名     | character varying |          |               |
 事業所名カナ | character varying |          |               |
 事業所住所   | character varying |          |               |
 新住所CD     | character varying |          |               |
インデックス:
    "comb_idx" btree ("郵便番号", "都道府県", "事業所名")

6.6.3. 調査・分析結果

■ 実行計画の確認

遅延が発生しているSQLの実行計画をEXPLAIN ANALYZEコマンドを用いて取得したところ、インデックススキャン(Index Scan)が選択されていました。 ただし、インデックススキャン時のcost値が高いことが確認できます。 また、インデックススキャン後にFilterにて多くのレコードが除外されています。 つまり、この結果から対象のSQLに対して複合インデックスが効率的に使用できていないことが確認できます。

=# EXPLAIN ANALYZE SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "都道府県" IN ('東京都', '神奈川県', '埼玉県', '千葉県') AND "事業所名" LIKE '学校法人%';
                                                             QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using comb_idx on "全国住所"  (cost=0.56..163403.17 rows=888 width=67) (actual time=22.246..12028.735 rows=4230 loops=1)
   Index Cond: ((("事業所名")::text >= '学校法人'::text) AND (("事業所名")::text < '学校法?'::text))
   Filter: ((("事業所名")::text ~~ '学校法人%'::text) AND (("都道府県")::text = ANY ('{東京都,神奈川県,埼玉県,千葉県}'::text[])))
   Rows Removed by Filter: 4110 --- Index Scanにてレコードを取得した後、Filterにて多くのレコード(4,110行)を除外している
 Planning Time: 0.264 ms
 Execution Time: 12029.023 ms
(6 行)

■ 複合インデックス

上記の実行計画のインデックススキャンで使用されているインデックスは複合インデックス”comb_idx”となります。 複合インデックスは先頭側の(左側)列からデータの絞り込みを行った場合に最も効率的となりますが、対象のSQLでは、2番目(“都道府県”)と3番目(“事業所名”)でデータの絞り込みを行っています。 そのため、1番目(“郵便番号”)で検索結果の絞り込みが行われず、効率の悪い検索となっています。

複合インデックスの走査イメージ

■ 複合インデックスの定義を見直す、または新規の複合インデックスを作成

複合インデックスを定義する場合は、その複合インデックスを使用するSQLがどういったデータの絞り込みを行うかを想定して定義する必要があります。 今回調査対象となった遅延SQLには、もともと定義されていた複合インデックスでは効率が悪かったのですが、他に実行されているSQLにとっては効率的に使用されていることも考えられるため、複合インデックスの定義を変更する際には他のSQLへの影響も確認する必要があります。 他のSQLへの影響がないことが確認できれば、複合インデックスの定義順を変更することで同じインデックススキャンを選択する実行計画でも性能を改善することができます。 cost値は163403.17->22.29、SQL実行時間も12029.956 ms->6.111 msに改善されました。

=# BEGIN;
=# DROP INDEX comb_idx;
=# CREATE INDEX comb_idx ON "全国住所"("都道府県", "事業所名", "郵便番号");
=# COMMIT;
=# EXPLAIN ANALYZE SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "都道府県" IN ('東京都', '神奈川県', '埼玉県', '千葉県') AND "事業所名" LIKE '学校法人%';
                                                                                   QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using comb_idx on "全国住所"  (cost=0.56..22.29 rows=933 width=67) (actual time=0.052..5.335 rows=4230 loops=1)
   Index Cond: ((("都道府県")::text = ANY ('{東京都,神奈川県,埼玉県,千葉県}'::text[])) AND (("事業所名")::text >= '学校法人'::text) AND (("事業所名")::text < '学校法?'::text))
   Filter: (("事業所名")::text ~~ '学校法人%'::text)
 Planning Time: 0.151 ms
 Execution Time: 5.585 ms
(5 行)

また、他のSQLへの影響がある場合は新規で複合インデックスを作成する必要があります。 この場合、同じカラムに複数のインデックスを定義することになりますので、更新性能に若干の影響がでます。 性能試験にて問題がないかを確認したうえで、ご判断願います。

=# CREATE INDEX comb2_idx ON "全国住所"("都道府県", "事業所名");
=# \d "全国住所"
                        テーブル "public.全国住所"
      列      |        型         | 照合順序 | Null 値を許容 | デフォルト
--------------+-------------------+----------+---------------+------------
 住所CD       | character varying |          |               |
 都道府県CD   | character varying |          |               |
 市区町村CD   | character varying |          |               |
 町域CD       | character varying |          |               |
 郵便番号     | character varying |          |               |
 事業所フラグ | boolean           |          |               |
 廃止フラグ   | boolean           |          |               |
 都道府県     | character varying |          |               |
 都道府県カナ | character varying |          |               |
 市区町村     | character varying |          |               |
 市区町村カナ | character varying |          |               |
 町域         | character varying |          |               |
 町域カナ     | character varying |          |               |
 町域補足     | character varying |          |               |
 京都通り名   | character varying |          |               |
 字丁目       | character varying |          |               |
 字丁目カナ   | character varying |          |               |
 補足         | text              |          |               |
 事業所名     | character varying |          |               |
 事業所名カナ | character varying |          |               |
 事業所住所   | character varying |          |               |
 新住所CD     | character varying |          |               |
インデックス:
    "comb2_idx" btree ("都道府県", "事業所名")
    "comb_idx" btree ("郵便番号", "都道府県", "事業所名")

=# EXPLAIN ANALYZE SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "都道府県" IN ('東京都', '神奈川県', '埼玉県', '千葉県') AND "事業所名" LIKE '学校法人%';
                                                                                   QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using comb2_idx on "全国住所"  (cost=0.56..22.29 rows=932 width=67) (actual time=0.035..5.581 rows=4230 loops=1)
   Index Cond: ((("都道府県")::text = ANY ('{東京都,神奈川県,埼玉県,千葉県}'::text[])) AND (("事業所名")::text >= '学校法人'::text) AND (("事業所名")::text < '学校法?'::text))
   Filter: (("事業所名")::text ~~ '学校法人%'::text)
 Planning Time: 0.222 ms
 Execution Time: 5.898 ms
(5 行)

6.6.4. 性能トラブルの改善案

複合インデックスでは、先頭列(左側)で定義したカラムから検索結果の絞り込みを行うことで最も効率の良くインデックスを使用します。 この時に、先頭列(左側)で定義したカラムでほとんど検索結果の絞り込みが行えなかったり、複合インデックスの定義に検索条件に含まれていないカラムが含まれていなかったりすると例え実行計画でインデックスが使用されていても非常に効率の悪いものになります。 (たいていの場合は、複合インデックスは使用されず、シーケンシャルスキャンが選択されます。) 上記の場合においては、遅延しているSQLでの検索条件と複合インデックスの定義順が適切でないため、複合インデックスの定義順を見直す必要があります。

本事例で紹介したケースでも、複合インデックスの定義順を見直すことでコスト値(CPU負荷)の低いインデックススキャンが実行されるようになり、処理性能を改善することが確認できました。

6.6.5. 備考

初期状態で実行計画を確認した時には、インデックススキャンが選択されているので問題ないと判断されますが、実データの増加に伴い性能トラブルが発生することがあります。 本件では、SQLの検索条件に対し、使用された複合インデックスの定義順が適切でないことが性能トラブルの原因となっています。 実行計画を確認する際には、演算子だけでなく予想されるコストに対しても適切かどうかを判断することを推奨いたします。

6.7. ロケール”C”以外でのインデックスの演算子クラスの定義漏れによる性能トラブル

6.7.1. 概要

PostgreSQLではデータベース毎にロケールを設定でき、データベース内での文字列処理、日付や通貨の表示、メッセージの言語などを変更することができます。 このように、ロケールの設定をすることで国や地域によって異なる表記や比較規則に対応することができます。 ただし、ロケールの設定は以下のSQL機能に影響を与えます。

  • 文字列データに対するORDER BYまたは標準の比較演算子を使用した問い合わせにおける並び替え順
  • upper、lower、initcap関数
  • (LIKE、SIMILAR TOやPOSIX形式の正規表現といった)パターンマッチング演算子では ロケールは大文字、小文字を区別せず正規表現の文字クラスによる文字の区別に影響を及ぼします。
  • 一群のto_char関数
  • LIKE節が付いたインデックスを使用する性能

上記にありますようにロケールを指定した状態で前方一致検索を行った場合に、インデックスが使用されずに性能トラブルを引き起こすことがあります。 このような場合は、組み込み演算子クラスを指定したインデックスを再作成する必要があります。

下記に「ロケール”C”以外でのインデックスの演算子クラスの定義漏れによる性能トラブル」についての事例を記載します。

6.7.2. 性能トラブル内容

アプリケーションに前方一致検索によるパターンマッチ処理を追加したが、このSELECT処理が遅延し、PostgreSQLログファイルに遅延SQLとして出力されています。

■ ログの確認状況

今回例示ではSQL遅延の閾値を3秒としているため、「log_min_duration_statement = 3s」に指定し、遅延が発生したSQLをPostgreSQLのログファイルに出力しています。

LOG:  duration: 10389.072 ms  statement: SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "市区町村" LIKE '川崎%';

遅延が発生するSQLは、ログファイルから抜粋した以下です。

SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "市区町村" LIKE '川崎%';

■ テーブル定義

遅延が発生するSQLでは、”全国住所”テーブルの”市区町村”カラムに対して前方一致検索を実施しています。 対象のカラムに対してインデックスは定義されています。テーブルの定義は以下の通りです。

=# \d "全国住所"
                        テーブル "public.全国住所"
      列      |        型         | 照合順序 | Null 値を許容 | デフォルト
--------------+-------------------+----------+---------------+------------
 住所CD       | character varying |          |               |
 都道府県CD   | character varying |          |               |
 市区町村CD   | character varying |          |               |
 町域CD       | character varying |          |               |
 郵便番号     | character varying |          |               |
 事業所フラグ | boolean           |          |               |
 廃止フラグ   | boolean           |          |               |
 都道府県     | character varying |          |               |
 都道府県カナ | character varying |          |               |
 市区町村     | character varying |          |               |
 市区町村カナ | character varying |          |               |
 町域         | character varying |          |               |
 町域カナ     | character varying |          |               |
 町域補足     | character varying |          |               |
 京都通り名   | character varying |          |               |
 字丁目       | character varying |          |               |
 字丁目カナ   | character varying |          |               |
 補足         | text              |          |               |
 事業所名     | character varying |          |               |
 事業所名カナ | character varying |          |               |
 事業所住所   | character varying |          |               |
 新住所CD     | character varying |          |               |
インデックス:
    "address_idx" btree ("市区町村")

6.7.3. 調査・分析結果

■ 実行計画の確認

遅延が発生しているSQLの実行計画をEXPLAIN ANALYZEコマンドを用いて取得したところ、以下のようにテーブルスキャンでシーケンシャルスキャン(Seq Scan)が選択されていました。 対象のカラムにインデックスが定義されているにも関わらず、インデックスが使用されていないことが確認できます。

=# EXPLAIN ANALYZE SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "市区町村" LIKE '川崎%';
                                                     QUERY PLAN
---------------------------------------------------------------------------------------------------------------------
 Seq Scan on "全国住所"  (cost=0.00..162695.88 rows=313 width=67) (actual time=13.477..14176.979 rows=12990 loops=1)
   Filter: (("市区町村")::text ~~ '川崎%'::text)
   Rows Removed by Filter: 4464870
 Planning Time: 0.078 ms
 Execution Time: 14178.363 ms
(5 行)

■ データベースのロケール

データベースのロケールを確認しました。 データベースのロケールでは、日本語対応のため”ja_JP.UTF8”に設定していることが確認できます。

=# \l <データベース名>
                                   データベース一覧
      名前        |  所有者  | エンコーディング |  照合順序  | Ctype(変換演算子) | アクセス権限
------------------+----------+------------------+------------+-------------------+--------------
 <データベース名> | postgres | UTF8             | ja_JP.UTF8 | ja_JP.UTF8        |
(1 行)

■ 演算子クラスを指定し、インデックスを再作成

「C」ロケールを指定している(ロケールを使用しない)場合においては、パターンマッチ演算子LIKE、ILIKE、~および~*を含む問い合わせでもそのパターンが先頭文字を指定している場合であればB-treeインデックスを使用することができます。 (Cロケールでのパターンマッチ問い合わせでは、デフォルト演算子クラスを使用したインデックスが使用できるためです。)

ロケールを指定している場合は、そのロケール特有の照合規則に従った処理を行いますので、インデックスが使用されなくなります。 [1] この場合、ロケール特有の照合規則に従わずに文字同士を厳密に比較する必要がありますので、インデックスを作成するときに演算子クラス [2] を指定します。 演算子クラス [2] とは特定のデータ型がインデックスでどのように使用されるかを定義したもので、演算子クラス [2] を指定することで、その列のインデックスで使用される演算子が特定されますので、文字列比較などのパターンマッチに適したインデックスとなります。

[1]ロケールのサポート
[2](1, 2, 3) 演算子クラスと演算子族

その結果、インデックスが使用されるようになり、実行計画上でもインデックススキャンが選択されていることが確認できます。 SQL実行時間も14179.046 ms->10.995 msに改善されました。

=# BEGIN;
=# DROP INDEX address_idx;
=# CREATE INDEX address_idx ON "全国住所" ("市区町村" varchar_pattern_ops);
=# COMMIT;
=# \d "全国住所"
                        テーブル "public.全国住所"
      列      |        型         | 照合順序 | Null 値を許容 | デフォルト
--------------+-------------------+----------+---------------+------------
 住所CD       | character varying |          |               |
 都道府県CD   | character varying |          |               |
 市区町村CD   | character varying |          |               |
 町域CD       | character varying |          |               |
 郵便番号     | character varying |          |               |
 事業所フラグ | boolean           |          |               |
 廃止フラグ   | boolean           |          |               |
 都道府県     | character varying |          |               |
 都道府県カナ | character varying |          |               |
 市区町村     | character varying |          |               |
 市区町村カナ | character varying |          |               |
 町域         | character varying |          |               |
 町域カナ     | character varying |          |               |
 町域補足     | character varying |          |               |
 京都通り名   | character varying |          |               |
 字丁目       | character varying |          |               |
 字丁目カナ   | character varying |          |               |
 補足         | text              |          |               |
 事業所名     | character varying |          |               |
 事業所名カナ | character varying |          |               |
 事業所住所   | character varying |          |               |
 新住所CD     | character varying |          |               |
インデックス:
    "address_idx" btree ("市区町村" varchar_pattern_ops)

=# EXPLAIN ANALYZE SELECT "郵便番号", "都道府県", "市区町村", "事業所名" FROM "全国住所" WHERE "市区町村" LIKE '川崎%';
                                                          QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
 Index Scan using address_idx on "全国住所"  (cost=0.43..8.45 rows=313 width=67) (actual time=0.034..9.406 rows=12990 loops=1)
   Index Cond: ((("市区町村")::text ~>=~ '川崎'::text) AND (("市区町村")::text ~<~ '川?'::text))
   Filter: (("市区町村")::text ~~ '川崎%'::text)
 Planning Time: 0.300 ms
 Execution Time: 10.135 ms
(5 行)

6.7.4. 性能トラブルの改善案

PostgreSQLで辞書順でソートしたい場合、ロケールを変更する必要があります。ロケールを指定することで実行速度が遅くなったり、LIKEで通常のインデックスが使用されなくなるなどの欠点があることをご注意願います。 上記の場合においては、インデックスを作成する際に演算子クラスを定義することで、インデックスで使用される演算子を特定し、正しい文字列比較ができるようにする必要があります。

本事例で紹介したケースでも、インデックス作成時に演算子クラスを指定することでパターンマッチ演算子を含むSQLでもインデックスを使用するようになり、処理性能を改善することが確認できました。

6.7.5. 備考

ロケールC環境と日本語ロケール環境でのソートおよび前方一致検索での性能差を確認するために試験を実施しました。 pgbenchで生成した、1,000,000(100万件)のデータが格納されるpgbench_accountsテーブルを利用しています。 pgbench_accountsテーブルのfillerカラムにmd5で文字列データを挿入し、インデックスを作成します。 該当のインデックスを使用し、ソート処理ならびに前方一致検索を行い、それぞれの実行時間を測定します。

(テーブル作成)
$ psql <データベース名>
=# CREATE TABLE "全国住所" (
    "住所CD" varchar,
    "都道府県CD" varchar,
    "市区町村CD" varchar,
    "町域CD" varchar,
    "郵便番号" varchar,
    "事業所フラグ" bool,
    "廃止フラグ" bool,
    "都道府県" varchar,
    "都道府県カナ" varchar,
    "市区町村" varchar,
    "市区町村カナ" varchar,
    "町域" varchar,
    "町域カナ" varchar,
    "町域補足" varchar,
    "京都通り名" varchar,
    "字丁目" varchar,
    "字丁目カナ" varchar,
    "補足" text,
    "事業所名" varchar,
    "事業所名カナ" varchar,
    "事業所住所" varchar,
    "新住所CD" varchar
);

(ソート時間測定方法)
=# \timing
=# SELECT "郵便番号", "都道府県", "市区町村" FROM "全国住所" ORDER BY "市区町村";

(前方一致検索時間測定方法)
=# \timing
=# SET max_parallel_workers_per_gather TO '0';
=# CREATE INDEX address_idx ON "全国住所"("市区町村", "都道府県");
=# SELECT "郵便番号", "都道府県", "市区町村" FROM "全国住所" WHERE "市区町村" LIKE '川崎%';

(ソート時間測定)
-ロケールC-
時間: 204.280 ミリ秒
時間: 209.477 ミリ秒
時間: 196.086 ミリ秒
-日本語ロケール-
時間: 3084.215 ミリ秒(00:03.084)
時間: 3076.427 ミリ秒(00:03.076)
時間: 3037.376 ミリ秒(00:03.037)

(前方一致検索時間測定)
-ロケールC-
時間: 1.069 ミリ秒
時間: 0.984 ミリ秒
時間: 1.016 ミリ秒
-日本語ロケール-
時間: 32.921 ミリ秒
時間: 39.147 ミリ秒
時間: 30.075 ミリ秒

6.8. 複合インデックス追加のみで性能が出ない場合の対処方法

6.8.1. 概要

PostgreSQLを含めたリレーショナル・データベースでは、複合インデックスを追加することによる性能向上が期待できます。 しかし、それだけでは不十分で更に性能向上のためのチューニングが必要となる場合があります。 特に、パッケージ製品を使用している等、望ましくないSQLであることがわかっていてもSQLを書き換えることができない制約がある場合では、データベース側の機能を活用して性能向上を図る必要があります。

本ケースでは、複合インデックスの追加に加えて、PostgreSQLのパラレルクエリ機能を活用して、性能向上を図った例を紹介します。

6.8.2. 性能トラブル内容

OSSの監視ツールであるZabbixのデータベースとしてPostgreSQLを使用していました。 監視データの増加に伴い障害発生状況を監視するWeb画面のデータがいつまで経っても表示されなくなり、運用に支障が出るようになりました。

■ ログの確認状況

今回の例ではSQL遅延の閾値を3秒としているため、「log_min_duration_statement = 3s」に指定し、遅延が発生したSQLをPostgreSQLのログファイルに出力しています。

LOG:  duration: 26019.451 ms  statement: explain (analyze,buffers)
        SELECT DISTINCT e.eventid,e.clock,e.ns,e.objectid,e.acknowledged,er1.r_eventid
        FROM events e LEFT JOIN event_recovery er1 ON er1.eventid=e.eventid
        WHERE e.source='0' AND e.object='0' AND e.objectid='16821' AND e.eventid<='4020491' AND e.value='1'
        ORDER BY e.eventid DESC
        LIMIT 20
        ;

Web画面に表示するSQLの実行時間が、約26秒であることがわかりました。

■ テーブル定義

遅延が発生するSQLでは、”events”テーブルの”source”,”object”,”objectid”,”eventid”,”value”カラムを使用して、WHERE句でデータを絞り込んでいます。 一部のカラムには複合インデックスが定義されています。テーブルの定義は以下の通りです。

# \d events
        テーブル "public.events"
     列      |           型            | 照合順序 | Null 値を許容 |      デフォルト
-------------+-------------------------+----------+---------------+-----------------------
eventid      | bigint                  |          | not null      |
source       | integer                 |          | not null      | 0
object       | integer                 |          | not null      | 0
objectid     | bigint                  |          | not null      | '0'::bigint
clock        | integer                 |          | not null      | 0
value        | integer                 |          | not null      | 0
acknowledged | integer                 |          | not null      | 0
ns           | integer                 |          | not null      | 0
name         | character varying(2048) |          | not null      | ''::character varying
severity     | integer                 |          | not null      | 0
インデックス:
"events_pkey" PRIMARY KEY, btree (eventid)
"events_1" btree (source, object, objectid, clock)
"events_2" btree (source, object, clock)
〜以下省略〜

eventidへの主キー以外に、「events_1」と「events_2」のインデックスが張ってあることがわかります。 しかし、今回のSQLのWHERE句で使用しているカラムをすべて網羅したインデックスは定義されていません。

eventsテーブルとJoinするテーブル”event_recovery”の定義は以下の通りです。

=# \d event_recovery
         テーブル "public.event_recovery"
      列       |   型   | 照合順序 | Null 値を許容 | デフォルト
---------------+--------+----------+---------------+------------
 eventid       | bigint |          | not null      |
 r_eventid     | bigint |          | not null      |
 c_eventid     | bigint |          |               |
 correlationid | bigint |          |               |
 userid        | bigint |          |               |
インデックス:
    "event_recovery_pkey" PRIMARY KEY, btree (eventid)
    "event_recovery_1" btree (r_eventid)
    "event_recovery_2" btree (c_eventid)
〜以下省略〜

6.8.3. 調査・分析結果

■ 実行計画の確認

遅延が発生しているSQLの実行計画をEXPLAIN ANALYZEコマンドを用いて取得したところ、インデックススキャン(Index Scan)が選択されていました。 ただし、インデックススキャン時のcost値が高く、実行時間も約22秒と長いことが確認できます。 また、インデックススキャン後にFilter処理にて多くのレコードが除外されています。 これは、6.6. 複合インデックスの定義順誤りによる性能トラブル」 と類似した実行計画です。 しかし、今回のケースではインデックスの定義が誤っているのではなく、複合インデックスとして定義するカラムが不足しているので、WHERE句の条件での絞り込みをインデックススキャンだけで賄うことができていないことがわかります。

# EXPLAIN ANALYZE SELECT DISTINCT e.eventid,e.clock,e.ns,e.objectid,e.acknowledged,er1.r_eventid
FROM events e LEFT JOIN event_recovery er1 ON er1.eventid=e.eventid
WHERE e.source='0' AND e.object='0' AND e.objectid='16821' AND e.eventid<='4020491' AND e.value='1'
ORDER BY e.eventid DESC
LIMIT 20
;
                                                                        QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=43456.02..43456.32 rows=20 width=36) (actual time=25484.258..25486.001 rows=20 loops=1)
   ->  Unique  (cost=43456.02..43485.71 rows=1979 width=36) (actual time=25484.254..25484.266 rows=20 loops=1)
         ->  Sort  (cost=43456.02..43460.97 rows=1979 width=36) (actual time=25484.252..25484.254 rows=20 loops=1)
               Sort Key: e.eventid DESC, e.clock, e.ns, e.acknowledged, er1.r_eventid
               Sort Method: quicksort  Memory: 206kB
               ->  Gather  (cost=1001.00..43347.67 rows=1979 width=36) (actual time=96.458..25483.526 rows=2010 loops=1)
                      Workers Planned: 1
                      Workers Launched: 1
                      ->  Nested Loop Left Join  (cost=1.00..42149.77 rows=1164 width=36) (actual time=92.466..25310.058 rows=1005 loops=2)
                            ->  Parallel Index Scan using events_1 on events e  (cost=0.56..32574.56 rows=1164 width=28) (actual time=80.380..21875.993 rows=1005 loops=2)
                                  Index Cond: ((source = 0) AND (object = 0) AND (objectid = '16821'::bigint))
                                  Filter: ((eventid <= '4020491'::bigint) AND (value = 1))
                                  Rows Removed by Filter: 8280
                                   ->  Index Scan using event_recovery_pkey on event_recovery er1  (cost=0.43..8.23 rows=1 width=16) (actual time=3.413..3.413 rows=1 loops=2010)
                                         Index Cond: (eventid = e.eventid)
 Planning Time: 155.445 ms
 Execution Time: 25486.320 ms
(17 行)

尚、SQL自体の問題については、備考に記載しております。

6.8.4. 性能トラブルの改善案

■ 複合インデックス定義を追加

6.6. 複合インデックスの定義順誤りによる性能トラブル」 と同様に、既存のインデックスを削除したり変更したりすると、他のSQLへの影響が懸念されるので、新規にインデックスを追加します。

Filter処理を使わずに、インデックススキャンのみで処理されるようにするために、WHERE句の列が全て盛り込まれたインデックスを作成してみます。

但し、eventidが範囲検索（e.eventid<=‘4020491’）、それ以外は固定値指定ですので、追加する複合インデックスの列順は source , object , objectid , eventid , value でなく、 source , object , objectid , value , eventid で定義します。 この方が参照するインデックスのページ数がより少なくなることが期待できます。

# BEGIN;
# CREATE INDEX events_3_add ON events (source,object,objectid,value,eventid);
# COMMIT;
# EXPLAIN ANALYZE SELECT DISTINCT e.eventid,e.clock,e.ns,e.objectid,e.acknowledged,er1.r_eventid
FROM events e LEFT JOIN event_recovery er1 ON er1.eventid=e.eventid
WHERE e.source='0' AND e.object='0' AND e.objectid='16821' AND e.eventid<='4020491' AND e.value='1'
ORDER BY e.eventid DESC
LIMIT 20
;
                                                                            QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=14467.84..14468.14 rows=20 width=36) (actual time=12867.942..12869.913 rows=20 loops=1)
   ->  Unique  (cost=14467.84..14497.52 rows=1979 width=36) (actual time=12867.936..12867.949 rows=20 loops=1)
         ->  Sort  (cost=14467.84..14472.78 rows=1979 width=36) (actual time=12867.934..12867.935 rows=20 loops=1)
               Sort Key: e.eventid DESC, e.clock, e.ns, e.acknowledged, er1.r_eventid
               Sort Method: quicksort  Memory: 206kB
               ->  Gather  (cost=1001.00..14359.48 rows=1979 width=36) (actual time=24.483..12867.367 rows=2010 loops=1)
                     Workers Planned: 1
                     Workers Launched: 1
                     ->  Nested Loop Left Join  (cost=1.00..13161.58 rows=1164 width=36) (actual time=27.116..12548.490 rows=1005 loops=2)
                           ->  Parallel Index Scan Backward using events_3_add on events e  (cost=0.56..3586.37 rows=1164 width=28) (actual time=9.932..4404.946 rows=1005 loops=2)
                                 Index Cond: ((source = 0) AND (object = 0) AND (objectid = '16821'::bigint) AND (value = 1) AND (eventid <= '4020491'::bigint))
                           ->  Index Scan using event_recovery_pkey on event_recovery er1  (cost=0.43..8.23 rows=1 width=16) (actual time=8.099..8.099 rows=1 loops=2010)
                                 Index Cond: (eventid = e.eventid)
 Planning Time: 62.744 ms
 Execution Time: 12870.059 ms
(15 行)

前回、21秒近くかかっていた「events」テーブルの絞り込み処理が、インデックスアクセスだけで絞り込むことができるようになった結果、4秒まで縮まりました。

■ パラレルワーカ起動数の増加

しかし、後の処理で遅い処理があるため、全体の実行結果は12秒くらいです。 インデックス追加前よりは改善されましたが、ZabbixのWeb画面上の表示は体感的に遅いままでした。 遅い処理となっているのは「Nested Loop Left Join」で、「events」テーブルと「event_recovery」テーブルを結合する処理です。 「Workers Launched」で指定された1つのワーカープロセスが処理を実行しています。

ワーカープロセスの処理の詳細を把握するために、ANALYZEをVERBOSEオプション付きで実行してみました。

# EXPLAIN (ANALYZE,VERBOSE) SELECT DISTINCT e.eventid,e.clock,e.ns,e.objectid,e.acknowledged,er1.r_eventid
FROM events e LEFT JOIN event_recovery er1 ON er1.eventid=e.eventid
WHERE e.source='0' AND e.object='0' AND e.objectid='16821' AND e.eventid<='4020491' AND e.value='1'
ORDER BY e.eventid DESC
LIMIT 20
;
〜中略〜
               ->  Gather  (cost=1001.00..14359.48 rows=1979 width=36) (actual time=50.255..12831.467 rows=2010 loops=1)
                     Output: e.eventid, e.clock, e.ns, e.objectid, e.acknowledged, er1.r_eventid
                     Workers Planned: 1
                     Workers Launched: 1
                     ->  Nested Loop Left Join  (cost=1.00..13161.58 rows=1164 width=36) (actual time=38.982..12467.064 rows=1005 loops=2)
                           Output: e.eventid, e.clock, e.ns, e.objectid, e.acknowledged, er1.r_eventid
                           Inner Unique: true
                           Worker 0: actual time=28.449..12788.620 rows=996 loops=1
                           ->  Parallel Index Scan Backward using events_3_add on public.events e  (cost=0.56..3586.37 rows=1164 width=28) (actual time=19.447..4433.804 rows=1005 loops=2)
〜以下略〜

ワーカー「Worker 0」の処理時間が、12秒近くかかっておりました。 そこで、ワーカープロセス数を増やして、処理時間を短縮することを試みてみます。

max_worker_processes=20
デフォルト値の8→20に変更

max_parallel_workers=16
デフォルト値の8→16に変更

max_parallel_workers_per_gather=15
デフォルト値の2→15に変更

ワーカー毎に物理CPUが必要なので、サーバーのCPUの個数を20個に増やします。 また、SELECT文の実行計画でパラレルクエリが適用されるようにevnetsテーブルとevent_recoveryテーブルへのparallel workersの数を設定します。

# alter table events set (parallel_workers=15) ;
# alter table event_recovery set (parallel_workers=15) ;
# EXPLAIN (ANALYZE,VERBOSE) SELECT DISTINCT e.eventid,e.clock,e.ns,e.objectid,e.acknowledged,er1.r_eventid
FROM events e LEFT JOIN event_recovery er1 ON er1.eventid=e.eventid
WHERE e.source='0' AND e.object='0' AND e.objectid='16821' AND e.eventid<='4020491' AND e.value='1'
ORDER BY e.eventid DESC
LIMIT 20
;
〜中略〜
               ->  Gather  (cost=1001.00..5859.80 rows=1979 width=36) (actual time=71.879..3512.788 rows=2010 loops=1)
                     Output: e.eventid, e.clock, e.ns, e.objectid, e.acknowledged, er1.r_eventid
                     Workers Planned: 15
                     Workers Launched: 15
                    ->  Nested Loop Left Join  (cost=1.00..4661.90 rows=132 width=36) (actual time=44.235..2316.473 rows=126 loops=16)
                           Output: e.eventid, e.clock, e.ns, e.objectid, e.acknowledged, er1.r_eventid
                           Inner Unique: true
                           Worker 0: actual time=40.852..2781.879 rows=166 loops=1
                           Worker 1: actual time=22.437..3165.144 rows=166 loops=1
                           Worker 2: actual time=68.658..3161.001 rows=166 loops=1
                           Worker 3: actual time=37.902..37.902 rows=0 loops=1
                           Worker 4: actual time=29.250..2957.890 rows=166 loops=1
                           Worker 5: actual time=37.862..37.862 rows=0 loops=1
                           Worker 6: actual time=37.009..2966.395 rows=166 loops=1
                           Worker 7: actual time=27.266..2901.912 rows=166 loops=1
                           Worker 8: actual time=41.792..2946.378 rows=166 loops=1
                           Worker 9: actual time=60.125..3198.788 rows=166 loops=1
                           Worker 10: actual time=64.219..3463.271 rows=166 loops=1
                           Worker 11: actual time=37.900..37.900 rows=0 loops=1
                           Worker 12: actual time=41.011..2896.906 rows=166 loops=1
                           Worker 13: actual time=32.507..2953.629 rows=166 loops=1
                           Worker 14: actual time=58.192..641.991 rows=31 loops=1
                           ->  Parallel Index Scan Backward using events_3_add on public.events e  (cost=0.56..3576.05 rows=132 width=28) (actual time=27.574..820.895 rows=126 loops=16)
〜以下略〜

ワーカーが15個起動し、最も遅いワーカーでも3秒まで縮めることができました。 以降の処理はボトルネックとなっていませんので、クエリー全体の実行時間を3秒近くまで縮めることができました。 ZabbixのWeb画面上の表示速度も改善されました。

6.8.5. 備考

  • 本ケースでは、パッケージ製品が発行したSQLに関する問題を、PostgreSQL側の機能とハードウェアリソースの増強で解決する案を紹介しました。別の観点として、対象データを減らすという考え方もあります。運用的に許容されるのであれば、対象データを定期的に削除するという方法もご検討ください。尚、今回のケースでは、監視データの保存期間をZabbix側で設定することによって定期的に削除することが可能です。

  • 本ケースはパッケージが発行したSQLなのでSQLを書き換えることができませんが、SQL自体の問題として、「LIMIT 20」と「DISTINCT」を併用しているという点があります。「DISTINCT」があるため、WHERE句で対象となる全件（2010件）を抽出する必要がありました。しかし、「DISTINCT」を無くすことができれば、WHERE句のeventidの逆順検索で20件を抽出するにとどめることによって、インデックス追加やパラメータを変更することなく、処理時間を短縮することが可能であることを確認しました。参考までに、「DISTINCT」を無くしたSQLの実行計画を記載いたします。

    # EXPLAIN ANALYZE SELECT e.eventid,e.clock,e.ns,e.objectid,e.acknowledged,er1.r_eventid
FROM events e LEFT JOIN event_recovery er1 ON er1.eventid=e.eventid
WHERE e.source='0' AND e.object='0' AND e.objectid='16821' AND e.eventid<='4020491' AND e.value='1'
ORDER BY e.eventid DESC
LIMIT 20
;
                                                              QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------
Limit  (cost=0.87..2207.66 rows=20 width=36) (actual time=51.519..1441.340 rows=20 loops=1)
  ->  Nested Loop Left Join  (cost=0.87..218362.90 rows=1979 width=36) (actual time=51.511..1441.321 rows=20 loops=1)
        ->  Index Scan Backward using events_pkey on events e  (cost=0.44..202083.40 rows=1979 width=28) (actual time=24.283..1215.563 rows=20 loops=1)
              Index Cond: (eventid <= '4020491'::bigint)
              Filter: ((source = 0) AND (object = 0) AND (objectid = '16821'::bigint) AND (value = 1))
              Rows Removed by Filter: 37875
        ->  Index Scan using event_recovery_pkey on event_recovery er1  (cost=0.43..8.23 rows=1 width=16) (actual time=11.284..11.284 rows=1 loops=20)
              Index Cond: (eventid = e.eventid)
Planning Time: 133.092 ms
Execution Time: 1441.580 ms
(10 行)

7. 著者

（企業・団体名順）

版 所属企業・団体名 部署名 氏名
第1.0版
(2017年度WG3)
 日本電気株式会社 AIプラットフォーム事業部 湯村 昇平
株式会社富士通ソーシアルサイエンスラボラトリ ソリューション開発センター ソリューションビジネス部 小山田 政紀
第2.0版
(2018年度WG3)
 サイオステクノロジー株式会社 技術1部 高岡 貴史
日本電気株式会社 AIプラットフォーム事業部 湯村 昇平
株式会社富士通ソーシアルサイエンスラボラトリ ソリューション開発センター ソリューションビジネス部 小山田 政紀
株式会社富士通ソーシアルサイエンスラボラトリ ソリューション開発センター ソリューション開発部 汪 キン垠
株式会社富士通ソーシアルサイエンスラボラトリ ソリューション開発センター ソリューションビジネス部 樊 小楚
第3.0版
(2019年度WG3)
 サイオステクノロジー株式会社 技術1部 高岡 貴史