[pgcluster: 600] Re: シーケンス番号の整合性が崩れる
kazunari takahashi
kazunari.takahashi ＠ ctc-g.co.jp
2004年 12月 6日 (月) 17:31:25 JST
三谷様
高橋です．
いつもお世話になっております．
以前、問い合わせたシーケンス番号の整合性が崩れる件ですが、また同じ現象が発生しました．
postgresql.logのログを参考に、現象を再現することができました．
insert文が複数のclusterDBに特定のタイミングで同時に発行されると起きる現象のようです．
postgresql.logを添付します．
####################################
#環境
####################################
pgcluster-1.0.8rc5
pglb × 2 (solaris8 sparc)
clusterDB ×2 (solaris8 sparc)(serverA,serverB)
rgrp × 2 (solaris8 sparc)
####################################
#検証方法
####################################
serverA% cat 1.sql
begin;
insert into test (name) values('ooo');
commit;
%cat xxx_4m.sql
serverB% cat xxx_4m.sql
BEGIN;
INSERT INTO test (name) values ('
xxx・・・・
・
・×4MB文
');
COMMIT;
serverBにて、
serverB% psql -h localhost -U test test < xxx_4m.sql
上記コマンドを実行後、20秒程経ってから、serverAにて、
serverA% psql -h localhost -U test test < 1.sql
#serverBでコマンド実行後、すぐにserverAで実行すると、IDの整合性がとれていました．
####################################
#SQLの結果
####################################
serverB:
test=> select * from test where name = 'ooo';
id | name
----+------
2 | ooo
(1 row)
serverA:
test=> select * from test where name = 'ooo';
id | name
----+------
1 | ooo
(1 row)
####################################
#postgresql.log
####################################
------------------------------
serverA:
------------------------------
Dec 6 13:50:51 serverA postgres[12483]: [ID 553393 local0.info] [1] LOG: query: begin; select getdatabaseencoding(); commit
Dec 6 13:50:51 serverA postgres[12483]: [ID 553393 local0.info] [2] LOG: duration: 0.017348 sec
Dec 6 13:50:51 serverA postgres[12483]: [ID 553393 local0.info] [3] LOG: query: SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1102308651,15340,2)
Dec 6 13:50:51 serverA postgres[12483]: [ID 553393 local0.info] [4] LOG: duration: 0.013620 sec
Dec 6 13:50:51 serverA postgres[12483]: [ID 553393 local0.info] [5] LOG: query: BEGIN
Dec 6 13:50:51 serverA postgres[12483]: [ID 553393 local0.info] [6] LOG: duration: 0.000713 sec
Dec 6 13:51:10 serverA postgres[12483]: [ID 748848 local0.info] [7-1] LOG: query: INSERT INTO test (name) values ('
Dec 6 13:51:10 serverA postgres[12483]: [ID 748848 local0.info] [7-2] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:10 serverA postgres[12483]: [ID 748848 local0.info] [7-3] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
・
・
・
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10215] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10216] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10217] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:13 serverA postgres[12493]: [ID 553393 local0.info] [1] LOG: query: begin; select getdatabaseencoding(); commit
Dec 6 13:51:13 serverA postgres[12493]: [ID 553393 local0.info] [2] LOG: duration: 0.016917 sec
Dec 6 13:51:13 serverA postgres[12493]: [ID 553393 local0.info] [3] LOG: query: BEGIN; SELECT usesuper FROM pg_catalog.pg_user WHERE usename = 'test'; COMMIT
Dec 6 13:51:13 serverA postgres[12493]: [ID 553393 local0.info] [4] LOG: duration: 0.027159 sec
Dec 6 13:51:13 serverA postgres[12493]: [ID 553393 local0.info] [5] LOG: query: begin;
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10218] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10219] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10220] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:13 serverA postgres[12483]: [ID 748848 local0.info] [7-10221] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
・
・
・
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10503] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10504] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10505] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10506] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12493]: [ID 553393 local0.info] [6] LOG: duration: 0.195062 sec
Dec 6 13:51:14 serverA postgres[12493]: [ID 553393 local0.info] [7] LOG: query: insert into test (name) values('ooo');
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10507] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10508] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10509] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10510] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10511] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10512] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10513] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10514] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12493]: [ID 553393 local0.info] [8] LOG: duration: 0.020317 sec
Dec 6 13:51:14 serverA postgres[12493]: [ID 553393 local0.info] [9] LOG: query: commit;
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10515] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10516] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-10517] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
・
・
・
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-11121] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-11122] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-11123] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverA postgres[12493]: [ID 553393 local0.info] [10] LOG: duration: 0.129258 sec
Dec 6 13:51:14 serverA postgres[12483]: [ID 748848 local0.info] [7-11124] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
・
・
・
Dec 6 13:51:24 serverA postgres[12483]: [ID 748848 local0.info] [7-39999] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:24 serverA postgres[12483]: [ID 748848 local0.info] [7-40000] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:24 serverA postgres[12483]: [ID 748848 local0.info] [7-40001] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:24 serverA postgres[12483]: [ID 748848 local0.info] [7-40002] ')
Dec 6 13:51:27 serverA postgres[12483]: [ID 553393 local0.info] [8] LOG: duration: 17.281247 sec
Dec 6 13:51:27 serverA postgres[12483]: [ID 553393 local0.info] [9] LOG: query: COMMIT
Dec 6 13:51:27 serverA postgres[12483]: [ID 553393 local0.info] [10] LOG: duration: 0.115568 sec
------------------------------
serverB:
------------------------------
Dec 6 13:50:50 serverB postgres[3741]: [ID 553393 local0.info] [1] LOG: query: begin; select getdatabaseencoding(); commit
Dec 6 13:50:50 serverB postgres[3741]: [ID 553393 local0.info] [2] LOG: duration: 0.020284 sec
Dec 6 13:50:50 serverB postgres[3741]: [ID 553393 local0.info] [3] LOG: query: BEGIN; SELECT usesuper FROM pg_catalog.pg_user WHERE usename = 'test'; COMMIT
Dec 6 13:50:51 serverB postgres[3741]: [ID 553393 local0.info] [4] LOG: duration: 0.031870 sec
Dec 6 13:50:51 serverB postgres[3741]: [ID 553393 local0.info] [5] LOG: query: BEGIN;
Dec 6 13:50:51 serverB postgres[3741]: [ID 553393 local0.info] [6] LOG: duration: 0.157712 sec
Dec 6 13:50:55 serverB postgres[3741]: [ID 748848 local0.info] [7-1] LOG: query: INSERT INTO test (name) values ('
Dec 6 13:50:55 serverB postgres[3741]: [ID 748848 local0.info] [7-2] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:50:55 serverB postgres[3741]: [ID 748848 local0.info] [7-3] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:50:55 serverB postgres[3741]: [ID 748848 local0.info] [7-4] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:50:55 serverB postgres[3741]: [ID 748848 local0.info] [7-5] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:50:55 serverB postgres[3741]: [ID 748848 local0.info] [7-6] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
・
・
・
Dec 6 13:51:01 serverB postgres[3741]: [ID 748848 local0.info] [7-39670] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:01 serverB postgres[3741]: [ID 748848 local0.info] [7-39671] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:01 serverB postgres[3741]: [ID 748848 local0.info] [7-39672] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:01 serverB postgres[3741]: [ID 748848 local0.info] [7-39673] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [1] LOG: query: begin; select getdatabaseencoding(); commit
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [2] LOG: duration: 0.024095 sec
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [3] LOG: query: SELECT PGR_SYSTEM_COMMAND_FUNCTION(3,1102308673,950934,2)
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [4] LOG: duration: 0.016216 sec
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [5] LOG: query: begin
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [6] LOG: duration: 0.000363 sec
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [7] LOG: query: insert into test (name) values('ooo')
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [8] LOG: duration: 0.010933 sec
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [9] LOG: query: commit
Dec 6 13:51:14 serverB postgres[3748]: [ID 553393 local0.info] [10] LOG: duration: 0.095987 sec
Dec 6 13:51:27 serverB postgres[3741]: [ID 553393 local0.info] [8] LOG: duration: 32.623963 sec
Dec 6 13:51:27 serverB postgres[3741]: [ID 553393 local0.info] [9] LOG: query: COMMIT;
Dec 6 13:51:27 serverB postgres[3741]: [ID 553393 local0.info] [10] LOG: duration: 0.169633 sec
以上 宜しくお願いいたします．
高橋 一成 <kazunari.takahashi ＠ ctc-g.co.jp>
pgcluster メーリングリストの案内