Julian Scarfe julian
Thu Aug 17 01:02:00 PDT 2006
So my next problem on testing 1.2RC3 looks like this.

After initialization...

---
init cluster (id = 1, comment = 'Node 1');
store node (id = 2, comment = 'Node 2');
store path (server = @node1, client = @node2, conninfo = @conninfo1);
store path (server = @node2, client = @node1, conninfo = @conninfo2);
---

...I create my sets (in a separate slonik script)

---
create set    (id = 1001, @origin1, comment = 'aeronautical_base');

set add table (set @set_aeronautical_base, @origin1, id = 1002, full 
qualified name = 'public.geonode', comment = 'Table public.geonode');
set add table (set @set_aeronautical_base, @origin1, id = 1003, full 
qualified name = 'public.geoedge', comment = 'Table public.geoedge');
... total of 10 tables in @set_aeronautical_base = 1001...
---

That seems to work fine.  When I start slon for each node, it stays running 
without error.

If I now add a second set to the set creation script...
---
create set    (id = 2001, @origin1, comment = 'aeronautical_extra');
set add table (set @set_aeronautical_extra, @origin1, id = 2002, full 
qualified name = 'public.aipinfo', comment = 'Table public.aipinfo');
set add table (set @set_aeronautical_extra, @origin1, id = 2003, full 
qualified name = 'public.airfieldinfo', comment = 'Table public.airfieldi
nfo');
... total of 6 tables in @set_aeronautical_extra = 2001...
---

...then starting from a clean install (i.e. uninstalling on each node and 
reinitializing),  I get the following fatal error on the slave when slon is 
started:

2006-08-17 07:53:38 UTC ERROR  remoteWorkerThread_1: "begin transaction; set 
transaction isolation level serializable; lock table "_T1".sl_config_lock; 
select "_T1".storeSet_int(2001, 1, 'aeronautical_extra'); notify 
"_T1_Event"; notify "_T1_Confirm"; insert into "_T1".sl_event 
(ev_origin, ev_seqno, ev_timestamp,      ev_minxid, ev_maxxid, ev_xip, 
ev_type , ev_data1, ev_data2, ev_data3    ) values ('1', '16', '2006-08-17 
07:50:53.779952', '36975500', '36975501', '', 'STORE_SET', '2001', '1', 
'aeronautical_extra'); insert into "_T1".sl_confirm        (con_origin, 
con_received, con_seqno, con_timestamp)    values (1, 2, '16', now()); 
commit transaction;" PGRES_FATAL_ERROR ERROR:  relation 
"PartInd_T1_sl_log_2-node-1" already exists
CONTEXT:  SQL statement "create index "PartInd_T1_sl_log_2-node-1" on 
"_T1".sl_log_2 USING btree(log_xid "_T1".xxid_ops) where (log_origin = 1);"
PL/pgSQL function "addpartiallogindices" line 30 at execute statement
SQL statement "SELECT  "_T1".addPartialLogIndices()"
PL/pgSQL function "storeset_int" line 31 at perform

Any ideas please?  I believe this worked fine under 1.1.5.

Thanks

Julian


Full log below (conninfo snipped):

2006-08-17 07:53:38 UTC CONFIG main: slon version 1.2.0 starting up
2006-08-17 07:53:38 UTC DEBUG2 slon: watchdog process started
2006-08-17 07:53:38 UTC DEBUG2 slon: watchdog ready - pid = 20589
2006-08-17 07:53:38 UTC DEBUG2 slon: worker process created - pid = 20861
2006-08-17 07:53:38 UTC CONFIG main: local node id = 2
2006-08-17 07:53:38 UTC DEBUG2 main: main process started
2006-08-17 07:53:38 UTC CONFIG main: launching sched_start_mainloop
2006-08-17 07:53:38 UTC CONFIG main: loading current cluster configuration
2006-08-17 07:53:38 UTC CONFIG storeNode: no_id=1 no_comment='Node 1'
2006-08-17 07:53:38 UTC DEBUG2 setNodeLastEvent: no_id=1 event_seq=15
2006-08-17 07:53:38 UTC CONFIG storePath: pa_server=1 pa_client=2 
pa_conninfo...
2006-08-17 07:53:38 UTC CONFIG storeListen: li_origin=1 li_receiver=2 
li_provider=1
2006-08-17 07:53:38 UTC CONFIG storeSet: set_id=1001 set_origin=1 
set_comment='aeronautical_base'
2006-08-17 07:53:38 UTC WARN   remoteWorker_wakeup: node 1 - no worker 
thread
2006-08-17 07:53:38 UTC DEBUG2 sched_wakeup_node(): no_id=1 (0 threads + 
worker signaled)
2006-08-17 07:53:38 UTC DEBUG2 main: last local event sequence = 1
2006-08-17 07:53:38 UTC CONFIG main: configuration complete - starting 
threads
2006-08-17 07:53:38 UTC DEBUG1 localListenThread: thread starts
2006-08-17 07:53:38 UTC DEBUG4 version for "dbname=avbrief" is 80104
2006-08-17 07:53:38 UTC CONFIG enableNode: no_id=1
2006-08-17 07:53:38 UTC DEBUG1 main: running scheduler mainloop
2006-08-17 07:53:38 UTC DEBUG1 remoteWorkerThread_1: thread starts
2006-08-17 07:53:38 UTC DEBUG1 remoteListenThread_1: thread starts
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: start listening for 
event origin 1
2006-08-17 07:53:38 UTC DEBUG4 version for "dbname=avbrief" is 80104
2006-08-17 07:53:38 UTC DEBUG4 remoteWorkerThread_1: update provider 
configuration
2006-08-17 07:53:38 UTC DEBUG1 cleanupThread: thread starts
2006-08-17 07:53:38 UTC DEBUG4 cleanupThread: bias = 35383
2006-08-17 07:53:38 UTC DEBUG1 syncThread: thread starts
2006-08-17 07:53:38 UTC DEBUG4 version for "dbname=avbrief" is 80104
2006-08-17 07:53:38 UTC DEBUG4 version for ...
2006-08-17 07:53:38 UTC DEBUG4 version for "dbname=avbrief" is 80104
2006-08-17 07:53:38 UTC DEBUG1 remoteListenThread_1: connected to ...
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,16 
STORE_SET
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,17 
SET_ADD_TABLE
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,18 
SET_ADD_TABLE
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,19 
SET_ADD_TABLE
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,20 
SET_ADD_TABLE
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,21 
SET_ADD_TABLE
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,22 
SET_ADD_TABLE
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,23 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,24 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,25 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,26 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,27 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,28 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,29 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,30 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,31 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,32 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,33 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,34 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,35 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,36 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteListenThread_1: queue event 1,37 SYNC
2006-08-17 07:53:38 UTC DEBUG2 remoteWorkerThread_1: Received event 1,16 
STORE_SET
2006-08-17 07:53:38 UTC CONFIG storeSet: set_id=2001 set_origin=1 
set_comment='aeronautical_extra'
2006-08-17 07:53:38 UTC DEBUG2 sched_wakeup_node(): no_id=1 (0 threads + 
worker signaled)
2006-08-17 07:53:38 UTC ERROR  remoteWorkerThread_1: "begin transaction; set 
transaction isolation level serializable; lock table "_T1".sl_config_lock; 
select "_T1".storeSet_int(2001, 1, 'aeronautical_extra'); notify 
"_T1_Event"; notify "_T1_Confirm"; insert into "_T1".sl_event 
(ev_origin, ev_seqno, ev_timestamp,      ev_minxid, ev_maxxid, ev_xip, 
ev_type , ev_data1, ev_data2, ev_data3    ) values ('1', '16', '2006-08-17 
07:50:53.779952', '36975500', '36975501', '', 'STORE_SET', '2001', '1', 
'aeronautical_extra'); insert into "_T1".sl_confirm        (con_origin, 
con_received, con_seqno, con_timestamp)    values (1, 2, '16', now()); 
commit transaction;" PGRES_FATAL_ERROR ERROR:  relation 
"PartInd_T1_sl_log_2-node-1" already exists
CONTEXT:  SQL statement "create index "PartInd_T1_sl_log_2-node-1" on 
"_T1".sl_log_2 USING btree(log_xid "_T1".xxid_ops) where (log_origin = 1);"
PL/pgSQL function "addpartiallogindices" line 30 at execute statement
SQL statement "SELECT  "_T1".addPartialLogIndices()"
PL/pgSQL function "storeset_int" line 31 at perform
2006-08-17 07:53:38 UTC DEBUG2 slon_retry() from pid=20861
2006-08-17 07:53:38 UTC DEBUG1 slon: retry requested
2006-08-17 07:53:38 UTC DEBUG2 slon: notify worker process to shutdown
2006-08-17 07:53:38 UTC INFO   remoteListenThread_1: disconnecting from ...
2006-08-17 07:53:38 UTC DEBUG1 remoteListenThread_1: thread done
2006-08-17 07:53:38 UTC DEBUG1 localListenThread: thread done
2006-08-17 07:53:38 UTC DEBUG1 main: scheduler mainloop returned
2006-08-17 07:53:38 UTC DEBUG2 main: wait for remote threads
2006-08-17 07:53:38 UTC DEBUG2 sched_wakeup_node(): no_id=1 (0 threads + 
worker signaled)
2006-08-17 07:53:38 UTC DEBUG1 cleanupThread: thread done
2006-08-17 07:53:38 UTC DEBUG1 syncThread: thread done
2006-08-17 07:53:38 UTC DEBUG1 main: done
2006-08-17 07:53:38 UTC DEBUG2 slon: child terminated status: 0; pid: 20861, 
current worker pid: 20861
2006-08-17 07:53:38 UTC DEBUG1 slon: restart of worker in 10 seconds







More information about the Slony1-general mailing list