On 7/24/2007 12:29 AM, Mikko Partio wrote:
> 
>     What I meant is that it'd be good to get enough detail information about
>     the specific actions that lead to this problem in order to create a
>     standalone test that can reproduce it.
> 
> 
> Ok here comes:

This one played quite a bit hide and seek with me. But I think I found 
and fixed the bug.

The problem occurred when some action (like STORE_SET) caused the 
subscriber slon to perform an internal restart. During that, the current 
setsync tracking in the pset structure is reinitialized. However, since 
the sl_setsync table is not updated on events other than SYNC, this 
would lead to the wrong (too low) old sync expected if the last event(s) 
processed from that node where no SYNC events.

Thanks for the detailed example.


Jan

> 
> I have three databases, test3 which is the primary, test3_lo which is 
> the secondary "loopback" database (only used to make the logshipping 
> logs) and test3_log, the logshipping database. All reside in the same pg 
> cluster. Here's exactly what I did, there's a lot of noise but I thought 
> it's better to be thorough.
> 
> 1) Create databases and some tables
> 
> $ createdb -D data -E utf8 test3
> $ psql test3
>    
> test3=# create table a (id int primary key);
> test3=# create table b (id int primary key);
> test3=# create table c (id int primary key);
> 
> $ createdb -T test3 test3_lo
> $ createdb -T test3 test3_log
> 
> 2) Create the replication cluster
> 
> $ cat test3_preamble.slonik
> cluster name = test3;
> 
> node 1 admin conninfo = 'host=localhost dbname=test3 user=postgres 
> password=xxx';
> node 2 admin conninfo = 'host=localhost dbname=test3_lo user=postgres 
> password=xxx';
> 
> $ cat test3_init.slonik
> #!/bin/sh
> 
> slonik <<_EOF_
> 
>         include <test3_preamble.slonik>;
> 
>         init cluster (id=1, comment='original database');
> 
>         store node (id=2, comment = 'dummy loopback database');
>         store path (server=1, client=2, conninfo='dbname=test3 
> host=localhost user=postgres password=xxx');
>         store path (server=2, client=1, conninfo='dbname=test3_lo 
> host=localhost user=postgres password=xxx');
>         store listen (origin=1, provider=1, receiver=2);
>         store listen (origin=2, provider=2, receiver=1);
> 
> _EOF_
> 
> $ ./test3_init.slonik
>    
> $ slon test3 "dbname=test3 host=localhost user=postgres password=xxx"
> $ slon -a /tmp/logshipping/test3 test3 "dbname=test3_lo host=localhost 
> user=postgres password=xxx"
> 
> $ cat test3_create_set.slonik
> #!/bin/sh
> 
> if [ $# -ne 3 ]; then
>         echo "Usage: $0 SETID TABLEID TABLENAME"
>         echo "Example: $0 3 17 public.x"
>         exit 1
> fi
> 
> slonik <<_EOF_
> 
>         include <test3_preamble.slonik>;
> 
>         create set (id=$1, origin=1, comment='Set #$1');
>         set add table (set id = $1, origin = 1, id = $2, fully qualified 
> name = '$3');
> 
> _EOF_
> 
> $ ./test3_create_set.slonik 1 1 public.a
> $ cat test3_subscribe.slonik
> #!/bin/sh
> 
> if [ -z $1 ]; then
>         echo "Usage: $0 SETID"
>         exit 1;
> fi
> 
> slonik <<_EOF_
> 
>         include <test3_preamble.slonik>;
> 
>         subscribe set (id=$1, provider=1, receiver=2, forward=no);
> 
> _EOF_
> 
> $ ./test3_subscribe.slonik 1
> $ psql test3_lo
> test3_lo=# \d a
>        Table " public.a"
>  Column |  Type   | Modifiers
> --------+---------+-----------
>  id     | integer | not null
> Indexes:
>     "a_pkey" PRIMARY KEY, btree (id)
> Triggers:
>     _test3_denyaccess_1 BEFORE INSERT OR DELETE OR UPDATE ON a FOR EACH 
> ROW EXECUTE PROCEDURE _test3.denyaccess('_test3')
> 
> $ psql test3
> test3=# insert into a select * from generate_series(1,100);
> 
> 3) Dump the state of the cluster to logshipping database
> 
> $ ./slony1_dump.sh test3_lo test3 | psql test3_log
> $ psql test3_log
> test3_log=# select count(*) from a;
>  count
> -------
>    100
> (1 row)
> 
> 4) Insert some data to origin db and see if it gets to logshipping db  
>   
> test3=# insert into a select * from generate_series(101,200);
> 
> $ psql -d test3_log -f 
> /tmp/logshipping/test3/slony1_log_1_00000000000000000060.sql    
> $ psql test3_log
> test3_log=# select count(*) from a;
>  count
> -------
>    200
> (1 row)
> 
> 5) Create another replication set
> 
> $ ./test3_create_set.slonik 10 2 public.b
> $ ./test3_subscribe.slonik 10
>    
> 6) Start applying logfiles to logshipping db
> 
> $ psql -d test3_log -f 
> /tmp/logshipping/test3/slony1_log_1_00000000000000000061.sql
> ...
> $ psql -d test3_log -f 
> /tmp/logshipping/test3/slony1_log_1_00000000000000000068.sql
> $ psql -d test3_log -f 
> /tmp/logshipping/test3/slony1_log_1_00000000000000000069.sql
> START TRANSACTION
> psql:/tmp/logshipping/test3/slony1_log_1_00000000000000000069.sql:6: 
> ERROR:  Slony-I: set 1 is on sync 68, this archive log expects 67
> 
> $ cat /tmp/logshipping/test3/slony1_log_1_00000000000000000068.sql
> -- Slony-I log shipping archive
> -- Node 1, Event 68
> start transaction;
> -- STORE_SET
> 
> select "_test3".setsyncTracking_offline(1, '67', '68', '2007-07-24 
> 07:14: 53.592719');
> -- end of log archiving header
> ------------------------------------------------------------------
> -- start of Slony-I data
> ------------------------------------------------------------------
> 
> ------------------------------------------------------------------
> -- End Of Archive Log
> ------------------------------------------------------------------
> commit;
> vacuum analyze "_test3".sl_setsync_offline;
> 
> 
> $ cat /tmp/logshipping/test3/slony1_log_1_00000000000000000069.sql
> -- Slony-I log shipping archive
> -- Node 1, Event 69
> start transaction;
> -- SET_ADD_TABLE
> 
> select "_test3".setsyncTracking_offline(1, '67', '69', '2007-07-24 
> 07:14: 53.641896');
> -- end of log archiving header
> ------------------------------------------------------------------
> -- start of Slony-I data
> ------------------------------------------------------------------
> 
> ------------------------------------------------------------------
> -- End Of Archive Log
> ------------------------------------------------------------------
> commit;
> vacuum analyze "_test3".sl_setsync_offline;
> 
> 
> 
> I hope this was of any help, if you need any more info I'm happy to help.
> 
> Regards
> 
> MP
> 
> 
> ------------------------------------------------------------------------
> 
> _______________________________________________
> Slony1-general mailing list
> Slony1-general at lists.slony.info
> http://lists.slony.info/mailman/listinfo/slony1-general


-- 
#======================================================================#
# It's easier to get forgiveness for being wrong than for being right. #
# Let's break this rule - forgive me.                                  #
#================================================== JanWieck at Yahoo.com #