[pgsql-jp: 41660] Re: pgpoolの縮退運転について

[岩田]

石井様、岩田です。

お返事ありがとうございます。毎回とても勉強、参考になります。

あれから、クエリログを調べてみましたら進展がありました。ただ、少し腑に落
ちない動きをしていたので確認させていただきたいです。

>>> おそらく切り離し自体は、UPDATE結果行数の相違という現象とはまた別の、
>>> replication_stop_on_mismatchに引っかかるような現象によって起こったのだ
>>> と思います。pgpool-IIのログがないので、それが何だったのかはわかりません。
>> ABORTと切り離しが二段階で評価されているのならば合点いきます。
>> しかし、結果行数が違ってABORTした上で切り離しまでする運用を良しとするか
>> は検討の必要がありますね。。それよりも、普通に運用していると きに、
>> UPDATE文の実行に失敗するケースはなんだろうと考えてしまいます。
> oidやrandom()等、バックエンド固有の状態に依存するクエリが含まれていませ
> んか？(該当のUPDATEだけでなく、以前実行されたINSERTも含めて)

"以前実行されたINSERT"というご指摘でピンときました。

# マスタ

2014-05-20 23:16:02 JST [58222]: [61036-1] LOG: statement: BEGIN
2014-05-20 23:16:02 JST [58222]: [61044-1] LOG: statement: INSERT
2014-05-20 23:16:06 JST [56956]: [60827-1] LOG: statement: BEGIN
2014-05-20 23:16:06 JST [56956]: [60831-1] LOG: statement: UPDATE
2014-05-20 23:16:06 JST [56956]: [60835-1] LOG: statement: ABORT
2014-05-20 23:16:07 JST [58222]: [61046-1] LOG: statement: COMMIT

# セカンダリ一台目

2014-05-20 23:16:02 JST [52719]: [73712-1] LOG: statement: BEGIN
2014-05-20 23:16:02 JST [52719]: [73716-1] LOG: statement: INSERT
2014-05-20 23:16:03 JST [52719]: [73718-1] LOG: statement: COMMIT
2014-05-20 23:16:06 JST [51974]: [75261-1] LOG: statement: BEGIN
2014-05-20 23:16:06 JST [51974]: [75265-1] LOG: statement: UPDATE
2014-05-20 23:16:06 JST [51974]: [75269-1] LOG: statement: ABORT

# セカンダリ二台目

2014-05-20 23:16:02 JST [14558]: [71786-1] LOG: statement: BEGIN
2014-05-20 23:16:02 JST [14558]: [71790-1] LOG: statement: INSERT
2014-05-20 23:16:06 JST [14558]: [71792-1] LOG: statement: COMMIT
2014-05-20 23:16:06 JST [13813]: [73769-1] LOG: statement: BEGIN
2014-05-20 23:16:06 JST [13813]: [73773-1] LOG: statement: UPDATE
2014-05-20 23:16:06 JST [13813]: [73777-1] LOG: statement: ABORT

上記は同じテーブルに対するINSERTとUPDATEのみを抽出したものですが。見事に
マスタのINSERTがCOMMITするまでに UPDATEが実行されており、セカンダリ×２と
はタイミングがずれているため、UPDATEで不一致が起きています。これがABORT
の原因な 気がします。そもそも、INSERTとUPDATEを同一トランザクションで処
理していないことが問題でした。

しかし、ここで疑問が浮かびます。

■ INSERTの実行開始時間が３台とも同じであること

"replication_mode = true"の場合、2.0以降、内部的に
は"replicate_strict=true"の挙動ですので、INSERTはマスタから実行され、完
了次 第、セカンダリ２台に並列に処理されると思っていました(昔作成された
SRAさんの2.0向けのプレゼン資料にはそう記載があったはずです)。実 は、同時
に並列にINSERTされる動きが正しくて、デットロックを防ぐ何かの仕組みがある
のでしょうか？

■ マスタだけINSERTのCOMMITまでに時間がかかること

INSERTによってインデックスが更新されるのでこれに時間がかかっているのか？
と思いますが、もちろんサーバーの状態によっては何とも言えま せんが、時間
がかかる原因はどのようなものが考えられるのでしょうか？

よろしくお願いいたします。