I have been experiencing errors due to pk violations on my slony
subscriber and could really use some suggestions.

I have tracked it down, using the postgres logs, to the same insert
statement being issued twice in succession.  The source data for that
insert only appears once in sl_log_1;

The insert that is duplicated (seen below in log output) is:
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330975','22008','500');

Here is a query of sl_log_1 that shows no duplicates:

marc# select * from _test_828.sl_log_1 where log_tableid = 6800 and log_cmddata like '%374330975%';
 log_origin | log_xid | log_tableid | log_actionseq | log_cmdtype |                      log_cmddata
------------+---------+-------------+---------------+-------------+--------------------------------------------------------------------------------
          1 | 2597097 |        6800 |      10080169 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22000','5')
          1 | 2597097 |        6800 |      10080170 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22011','0')
          1 | 2597097 |        6800 |      10080171 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22001','4')
          1 | 2597097 |        6800 |      10080172 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22002','3')
          1 | 2597097 |        6800 |      10080173 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22003','2')
          1 | 2597097 |        6800 |      10080174 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22004','2')
          1 | 2597097 |        6800 |      10080175 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22005','1')
          1 | 2597097 |        6800 |      10080176 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22006','8')
          1 | 2597097 |        6800 |      10080177 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22007','0')
          1 | 2597097 |        6800 |      10080180 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22008','500')
          1 | 2597097 |        6800 |      10080226 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22009','0')
          1 | 2597097 |        6800 |      10080227 | I           | (table_transaction_id,attribute_type,value) values ('374330975','22010','21')
(12 rows)

And here is a query showing the state of the matching data in the source database.

marc# select * from "public"."table_trans_attribute" where
table_transaction_id = 374330975;
 table_transaction_id | attribute_type | value
----------------------+----------------+-------
            374330975 |          22000 |     5
            374330975 |          22001 |     4
            374330975 |          22002 |     3
            374330975 |          22003 |     2
            374330975 |          22004 |     2
            374330975 |          22005 |     1
            374330975 |          22006 |     8
            374330975 |          22007 |     0
            374330975 |          22008 |   500
            374330975 |          22009 |     0
            374330975 |          22010 |    21
            374330975 |          22011 |     0
(12 rows)



Here is an extract from the logfile showing the error (including the
duplicate inserts):

2006-06-22 15:16:41 CST ERROR  remoteWorkerThread_1: "insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330975','22005','1');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330975','22006','8');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330975','22007','0');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330973','22011','0');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330973','22001','0');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330975','22008','500');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330975','22008','500');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330973','22002','0');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330973','22003','2');
insert into "public"."table_trans_attribute" (table_transaction_id,attribute_type,value) values ('374330973','22004','2');
" ERROR:  duplicate key violates unique constraint "table_trans_attr_pk"
 - qualification was: where log_origin = 1 and (  (
 log_tableid in (100,200,300,400,500,600,700,800,900,1000,1100,1300,1400,1500,1600,1800,1900,2000,2100,2200,2300,2400,2500,2600,2700,2800,2900,3000,3100,3200,3300,3400,3500,3600,3700,3800,3900,4000,4100,4200,4300,4400,4500,4600,4700,4800,4900,5000,5100,5200,5300,5400,5500,5600,5700,5800,5900,6000,6300,6400,6500,6800,6900,7000,7100,7200,7400,7500,7600,8000,8200,8300,10600,10700,11000,11100,11200,11300,11400,11500,11600,11700,12000,12100,12200,12300,12400,12500,12600,99999999)
    and (log_xid < '2598860' and "_test_828".xxid_lt_snapshot(log_xid, '1174322:2598860:''2598857'',''2598850'',''2598858'',''2598848'',''1174322'''))
    and (log_xid >= '1174322' and "_test_828".xxid_ge_snapshot(log_xid, '1174322:2596959:''2596956'',''1174322'''))
) )
2006-06-22 15:16:41 CST DEBUG2 remoteHelperThread_1_1: 194.265 seconds until close cursor
2006-06-22 15:16:41 CST ERROR  remoteWorkerThread_1: helper 1 finished with error
2006-06-22 15:16:42 CST ERROR  remoteWorkerThread_1: SYNC aborted
2006-06-22 15:16:45 CST DEBUG2 remoteListenThread_1: queue event 1,5522 SYNC


[To attempt to find corrupted indexes, I have repeated those queries,
driving them using indexes and got back the same data.  Here are the
query plans for the full set of queries:

marc# explain select * from _test_828.sl_log_1 where log_origin=1 and log_xid = '2597097'::_test_828.xxid and log_actionseq = 10080180;
                                                QUERY PLAN 
-----------------------------------------------------------------------------------------------------------
 Index Scan using sl_log_1_idx1 on sl_log_1  (cost=0.00..4.33 rows=1 width=121)
   Index Cond: ((log_origin = 1) AND (log_xid = '2597097'::_test_828.xxid) AND (log_actionseq = 10080180))
(2 rows)

marc# explain select * from "public"."table_trans_attribute" where table_transaction_id + 1 = 374330975 + 1;
                                   QUERY PLAN 
---------------------------------------------------------------------------------
 Seq Scan on table_trans_attribute  (cost=0.00..3038233.91 rows=700244 width=10)   Filter: ((table_transaction_id + 1) = 374330976)
(2 rows)

marc# explain select * from "public"."table_trans_attribute" where table_transaction_id = 374330975;
                                               QUERY PLAN 
--------------------------------------------------------------------------------------------------------
 Index Scan using table_trans_attr_pk on table_trans_attribute  (cost=0.00..5956.80 rows=3365 width=10)
   Index Cond: (table_transaction_id = 374330975)
(2 rows)

marc# explain select * from _test_828.sl_log_1 where log_tableid = 6800 and log_cmddata like '%374330975%';
                                QUERY PLAN
---------------------------------------------------------------------------
 Seq Scan on sl_log_1  (cost=0.00..2149159.56 rows=119 width=121)
   Filter: ((log_tableid = 6800) AND (log_cmddata ~~ '%374330975%'::text))
(2 rows)

__
Marc
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
Url : http://gborg.postgresql.org/pipermail/slony1-general/attachments/20060622/091a5f48/attachment-0001.bin