[pgsql-jp: 42004] Re: SELECT時のWALの大量出力について

[喜田 紘介]

板山様

喜田です。

チェックポイントのたびに、前回チェックポイント以降アクセスされた全てのページがfull page writesの対象になります。
（初回アクセスとは、あるチェックポイント以降の初回という意味で使っていました。）


checkpoint timeout が30分なので、たとえ無風でもチェックポイントは1日に何度も発生しているはずで、
その後のフルスキャンで（新たにinsertした分だけでなく）全件対象にFPWしたのだと思います。




2019/02/19 21:14、板山 <itayama-k ＠ evoltech.co.jp>のメール:

> 喜田様
> ご連絡ありがとうございます、板山です。
> 
> > wal_log_hints有効時は、SELECTでもWALを吐きます。
> > チェックポイント後は、初回アクセスされたページの..
> 
> はい、存じております。
> 
> 
> 以下の場合、472,945件分のページが、「初回アクセスされた」に
> 該当することになるように思うのですが..
> 
> ・1/16：181,135,541件有り、2回フルスキャン(seq_tup_read)
> ・1/22 12:00：181,608,486件分をWAL出力
> 
> 
> WALの出力量は、1億8千万件分あるように見受けられますが、
> 全件出力することもあるのでしょうか。
> 
> 
> 
>> On 2019/02/19 20:36, 喜田 紘介 wrote:
>> 喜田と申します。
>> メール冒頭にある「出力されないはずのWAL」とは、
>> この期間において「データの増／減／更新はありません。」だからでしょうか？
>> ★印で強調いただいていますので気になられているのだと思いますが、
>> wal_log_hints有効時は、SELECTでもWALを吐きます。
>> チェックポイント後は、、初回アクセスされたページの
>> イメージを丸ごとWALに吐く（full_page_writes）ので、
>> 何度か実施されたというフルスキャンでWALを吐いたのだと思います。
>> なにか見直すとすれば以下でしょうか。
>> ・WALはそれだけ生成されるものとしてWAL領域を増やす（併せてチェックポイントを頻発させないためにmax_wal_sizeも増やす）
>> ・pg_rewindのためのwal_log_hintsだと思うが、いざという時に原因不明で失敗するならwal_log_hintsを無効にする
>> ・wal_compressionを有効にしてWALサイズを小さくする（微々たる効果かもしれませんが）
>> 以上です。
>> 2019/02/19 19:10、板山 <itayama-k ＠ evoltech.co.jp>のメール:
>>> 板山と申します。
>>> 
>>> PostgreSQL9.6.9を利用しており、
>>> ストリーミングレプリケーションでクラスタを構成しております。
>>> 
>>> 出力されない筈のWALが大量に出力され、アーカイブ領域がパンクしました。
>>> 原因不明のため、対策が分からず、困っております。
>>> 
>>> 
>>> 状況は以下になります。
>>> 
>>> [参考]富士通 Systemwalker Service Quality Coordinator（SQC）という製品
>>> 　を導入しており、5分毎にPG_STAT_USER_TABLESとPG_STATIO_USER_TABLES等
>>> 　の情報を取得し、出力は10分毎に集計されます。
>>> 　時刻はUTCです。
>>> 
>>> history_901テーブルが有り、履歴テーブルでパーティション化しております。
>>> 2019年1月に他テーブルで登録したデータを履歴として登録します。
>>> 5年保持し、5年経つまでは insert/selectしか行いません。
>>> 
>>> 1/16に181,135,541件有り、indexが無いため 2回フルスキャン(seq_tup_read)
>>> しています。
>>> 1/17に非機能テストを実施し、1号機から2号機にPrimaryがswitchしました。
>>> この後、1号機をPrimaryに戻すため、2号機からpg_rewindを実行しましたが
>>> エラーになり、pg_basebackupで全コピーしました。
>>> 
>>> 1/17 6:00に181,144,152件あり、1/18 5:10～7:30のみ、
>>> SQCで情報を取得できていませんが、上記2h20mの後、
>>> データの増／減／更新はありません。
>>> 
>>> 1/22 12:00に「explain analyze select ～ from history_901」を実施し、
>>> 181,608,486件をseq_tup_readしました。
>>> PG_STATIO_USER_TABLESは、以下になっています。(約28.3GB)
>>> heap_blks_read：3,707,458
>>> heap_blks_hit ：　　　 35
>>> 
>>> PostgreSQLのログには「checkpoint complete」が68行出力され、
>>> 以下の数値を合計すると、28.3GBになります。
>>> removed ：　754
>>> recycled：1,059
>>> 合計　　：1,813　→28.3GB
>>> 
>>> これは、1億8千万件 全件をWALに出力していると思います。
>>> 全件WALに出力するのは、仕様通りだと あり得ないと思っております。
>>> 
>>> 全件UPDATEしていれば可能性があると思いますが、
>>> PG_STAT_USER_TABLESは、以下になっています。
>>> last_autovacuum ：現在まで全てNULL
>>> last_autoanalyze：2019/1/15 6:33 [*1]
>>> [*1]1/17に2号機からコピーしたため、1/17以降は全てNULL
>>> 
>>> 
>>> postgresql.confの主なパラメータは、以下になります。
>>> wal_level = replica
>>> #fsync = on
>>> #synchronous_commit = on
>>> #wal_sync_method = fsync
>>> #full_page_writes = on
>>> wal_log_hints = on　　　　　★
>>> checkpoint_timeout = 30min
>>> #max_wal_size = 1GB
>>> #min_wal_size = 80MB
>>> checkpoint_completion_target = 0.9
>>> synchronous_standby_names = '相手サーバ名'
>>> log_min_duration_statement = 15s
>>> #autovacuum = on
>>> #autovacuum_vacuum_threshold = 50
>>> #autovacuum_analyze_threshold = 50
>>> #autovacuum_vacuum_scale_factor = 0.2
>>> #autovacuum_analyze_scale_factor = 0.1
>>> 
>>> 
>>> なぜ 28GB（全件）もWALに出力されたのでしょうか。
>>> よろしくお願い致します。