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

2019年 2月 19日 (火) 15:04:32 UTC

澤田です。

2019年2月19日(火) 23:25 板山 <itayama-k ＠ evoltech.co.jp>:
>
> 澤田様
> ありがとうございます、板山です。
>
>  >1/16の 2回フルスキャンはmasterでの実行でしょうか？
>
> はい、そうです。
>
>
>  >1/16時点のmasterでもwal_log_hintsはonになっていたでしょうか？
>
> はい、なっております。
>
>
>
> 社内に 同一バージョン、同一パラメータの別環境があります。
> 何度か試してみたところ、
> insert→checkpoint後のselectでWALは出力されますが、
> 再度のselectでは出力されません。
>
> ヒントビットは、slaveも更新されているようです。
>
> 上記は、pg_xlogdumpを参照した際、「～FOR_HINT」と出力されるのが
> ヒントビットの更新と理解しており、
> WALファイルの増加と「～FOR_HINT」の出力で確認しております。
>

「FOR_HINT」のWALは、hint bitの更新を伝えるためのWALではなく、
checkpoint後初めてのhint bitの更新に伴いfull page writeが出たことを
表すWALだと思います（つまり、checkpoint後2回目のhint bit更新では
「FOR_HINT」のWALはでない）。そのため、masterとslaveではhint bitの状態が
一致していないことが多いです。
# レプリケーションではmaster、slave間のhint bitの状態の一致までは
# 保証していなかったと思います。

>
>
>  > チェックポイント後は、初回アクセスされたページの
>
> というのは、以下にある ヒントビットを更新しているから
> だと理解しております。
> そうであるなら、insert→checkpoint後の初回のselectのみが
> WAL出力の対象、と思うのですが..。

はい、その通りだと思います。insert -> checkpoint -> selectとすると、
insertした行のhint bitsが立つのでそれに伴いそのページのfull page writeが出力されます。
hint bitは行毎に付きますが、それに伴って出力されるのはページ全体(full page write)
なので、さらに同じページへinsert -> checkpoint -> selectとしても
selectの時に再度full page writeが出力されます。

上記の「masterとslaveのhint bitの状態が一致しない」についてですが、
例えば以下のようなケースです。

1. checkpoint
2. 数行insert
3. select
    -> hint bit更新
    -> full page writeが出力（2でinsertした行のhint bitも一緒に出力。これはslaveに伝わる)
4. pageいっぱいになるまでinsert
5. select
    -> hint bit更新
    -> full page writeは出力されない(4でinsertした行のhint bitはslaveに伝わらない)

master側のテーブルではすべてhint bitは立っているけど、
slave側のテーブルでは一部のタプルにはhint bitが立っていない状態となります。
5以降、同ページに対してINSERT/DELETE/UPDATEは起こらない限り、
slaveのhint bitはずっと更新されません。

以上です。

>
> http://www.nminoru.jp/~nminoru/postgresql/pg-table-and-block-structure.html
>
>
>
> ちなみに、富士通が出している「Enterprise Postgres」になります。
> 不具合では？　と懸念しております.. 。

コミュニティ版PostgreSQLの動きは上記の通りだと思いますが、
Enterprise Postgresでその辺を変更している可能性もあるので、
富士通さんに聞いてみるのもありかと思います。

以上です。

>
>
>
> On 2019/02/19 23:02, Masahiko Sawada wrote:
> > 澤田と申します。
> >
> > 2019年2月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千万件分あるように見受けられますが、
> >> 全件出力することもあるのでしょうか。
> >
> > slaveの状態によってはあると思います。
> > 1/17にslaveからmasterを構築しているので、例えば、その時にslave側のテーブルに
> > hint bitsが立っていない状態であれば、その後のmasterのフルスキャンで
> > 初めてhint bitが立ちテーブル全体分のWALが出力されます。
> >
> > 1/16の 2回フルスキャンはmasterでの実行でしょうか？
> > また、1/16時点のmasterでもwal_log_hintsはonになっていたでしょうか？
> > hint bitsの更新は、full page write以外でslaveに反映されなかったと思うので、
> > slaveでのフルスキャンであったり、1/16時点でmasterがwal_log_hints = offの場合は、
> > slaveのhint bitは立っていない状態だと思います。
> >
> > 以上です。
> >
> >>
> >>
> >>
> >> 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に出力されたのでしょうか。
> >>>> よろしくお願い致します。


-- 
--
Masahiko Sawada