[Bucardo-general] Bucardo 5 has arrived!

Thu May 19 23:51:46 UTC 2011

Yeah, I can't get it to replicate even a small 3-column test table in a 
sandbox database.  It seems to me that the cause is that this keeps 
happening:

May 19 19:50:21 db Bucardo[2204]: MCP Got NOTICE 
bucardo_kick_sync_netsip_sync 16 times from 588 (and 12 other PIDs) 
(line 755)
May 19 19:50:21 db Bucardo[2204]: MCP Received unknown message 
bucardo_kick_sync_netsip_sync from 588!
May 19 19:50:21 db Bucardo[2290]: CTL Controller 2290 exiting at 
cleanup_controller. Reason: Stop sync request at 
/usr/lib/perl5/site_perl/5.8.8/Bucardo.pm line 1435.

If I remove the 'die' statement around line 1435 just for kicks (no pun 
intended), it will sync some records before ceasing to do so.  So, my 
guess is that the sync is being aborted prematurely for some unknown reason.

On 05/18/2011 01:27 PM, Alex Balashov wrote:

> Preliminary results with one master and one target show data being
> transmitted on the wire (I did a packet capture on port 5432), but no
> actual data being changed, although PostgreSQL is not throwing any errors.
>
> This is the recurring theme of the Bucardo log:
>
> May 18 13:26:58 db Bucardo[21813]: CTL Connected to database "xxxxxx"
> with backend PID of 21815
> May 18 13:26:59 db Bucardo[20569]: MCP Got NOTICE
> bucardo_kick_sync_xxxxxx_cdr_sync 15 times from 572 (and 9 other PIDs)
> (line 754)
> May 18 13:26:59 db Bucardo[20569]: MCP Received unknown message
> bucardo_kick_sync_xxxxxx_cdr_sync from 572!
> May 18 13:26:59 db Bucardo[21813]: CTL Connected to database
> "xxxxxx_remote" with backend PID of 15432
> May 18 13:26:59 db Bucardo[21813]: CTL Got NOTICE
> stopsync_xxxxxx_cdr_sync from 21814 (Bucardo DB) (line 1411)
> May 18 13:26:59 db Bucardo[21813]: CTL Got a stop sync request, so exiting
> May 18 13:26:59 db Bucardo[21813]: CTL Warning! Controller for
> "xxxxxx_cdr_sync" was killed at line 1434: Stop sync request at
> /usr/lib/perl5/site_perl/5.8.8/Bucardo.pm line 1434.
> May 18 13:26:59 db Bucardo[21813]: CTL Sending NOTIFY
> "kid_stop_xxxxxx_cdr_sync" (line 5753)
> May 18 13:26:59 db Bucardo[20569]: MCP Got NOTICE
> bucardo_kick_sync_xxxxxx_cdr_sync 15 times from 568 (and 8 other PIDs)
> (line 754)
> May 18 13:26:59 db Bucardo[20569]: MCP Received unknown message
> bucardo_kick_sync_xxxxxx_cdr_sync from 568!
> May 18 13:27:00 db Bucardo[21813]: CTL Controller 21813 exiting at
> cleanup_controller. Reason: Stop sync request at
> /usr/lib/perl5/site_perl/5.8.8/Bucardo.pm line 1434.
> May 18 13:27:00 db Bucardo[21813]: CTL Removed pid file
> "/var/run/bucardo.ctl.sync.xxxxxx_cdr_sync.pid"
> May 18 13:27:00 db Bucardo[21813]: CTL Final database backend PID: 21816
> May 18 13:27:00 db Bucardo[21813]: CTL Made final adjustment to the
> syncrun table
> May 18 13:27:00 db Bucardo[20569]: MCP Got NOTICE
> bucardo_kick_sync_xxxxxx_cdr_sync 18 times from 567 (and 11 other PIDs)
> (line 754)
> May 18 13:27:00 db Bucardo[20569]: MCP Received unknown message
> bucardo_kick_sync_xxxxxx_cdr_sync from 567!
> May 18 13:27:00 db Bucardo[20569]: MCP Could not find controller 21813,
> will create a new one. Kicked is 0
> May 18 13:27:00 db Bucardo[20569]: MCP Checking for existing controllers
> for sync "xxxxxx_cdr_sync"
> May 18 13:27:00 db Bucardo[20569]: MCP Created controller 21817 for sync
> "xxxxxx_cdr_sync". Kick is 0
> May 18 13:27:00 db Bucardo[21817]: CTL Created
> /var/run/bucardo.ctl.sync.xxxxxx_cdr_sync.pid
> May 18 13:27:00 db Bucardo[21817]: CTL New controller for sync
> "xxxxxx_cdr_sync". Herd is "cdr", dbs is "xxxxxx_group". PID=21817
> May 18 13:27:00 db Bucardo[21817]: CTL stayalive: 1 checksecs: 0
> limitdbs: 0 kicked: 0
> May 18 13:27:00 db Bucardo[21817]: CTL kidsalive: 1 onetimecopy: 0
> lifetimesecs: 0 (NULL) maxkicks: 0
> May 18 13:27:00 db Bucardo[21817]: CTL Bucardo database backend PID: 21818
> May 18 13:27:00 db Bucardo[21817]: CTL LISTEN for "bucardo_ctl" on
> "bucardo" (line 1244)
> May 18 13:27:00 db Bucardo[21817]: CTL Sending NOTIFY
> "kid_stopsync_xxxxxx_cdr_sync" (line 1284)
> May 18 13:27:00 db Bucardo[21817]: CTL Sending NOTIFY
> "ctl_stopsync_xxxxxx_cdr_sync" (line 1286)
> May 18 13:27:00 db Bucardo[21817]: CTL Connected to database "xxxxxx"
> with backend PID of 21819
> May 18 13:27:00 db Bucardo[20569]: MCP Got NOTICE
> bucardo_kick_sync_xxxxxx_cdr_sync 14 times from 587 (and 10 other PIDs)
> (line 754)
> May 18 13:27:00 db Bucardo[20569]: MCP Received unknown message
> bucardo_kick_sync_xxxxxx_cdr_sync from 587!
> May 18 13:27:01 db Bucardo[21817]: CTL Connected to database
> "xxxxxx_remote" with backend PID of 15433
> May 18 13:27:01 db Bucardo[21817]: CTL Got NOTICE
> stopsync_xxxxxx_cdr_sync from 21818 (Bucardo DB) (line 1411)
> May 18 13:27:01 db Bucardo[21817]: CTL Got a stop sync request, so exiting
> May 18 13:27:01 db Bucardo[21817]: CTL Warning! Controller for
> "xxxxxx_cdr_sync" was killed at line 1434: Stop sync request at
> /usr/lib/perl5/site_perl/5.8.8/Bucardo.pm line 1434.
> May 18 13:27:01 db Bucardo[21817]: CTL Sending NOTIFY
> "kid_stop_xxxxxx_cdr_sync" (line 5753)
> May 18 13:27:01 db Bucardo[20569]: MCP Got NOTICE
> bucardo_kick_sync_xxxxxx_cdr_sync 13 times from 587 (and 10 other PIDs)
> (line 754)
> May 18 13:27:01 db Bucardo[20569]: MCP Received unknown message
> bucardo_kick_sync_xxxxxx_cdr_sync from 587!
> May 18 13:27:01 db Bucardo[21817]: CTL Controller 21817 exiting at
> cleanup_controller. Reason: Stop sync request at
> /usr/lib/perl5/site_perl/5.8.8/Bucardo.pm line 1434.
> May 18 13:27:01 db Bucardo[21817]: CTL Removed pid file
> "/var/run/bucardo.ctl.sync.xxxxxx_cdr_sync.pid"
> May 18 13:27:01 db Bucardo[21817]: CTL Final database backend PID: 21820
> May 18 13:27:01 db Bucardo[21817]: CTL Made final adjustment to the
> syncrun table
> May 18 13:27:01 db Bucardo[20569]: MCP Got NOTICE
> bucardo_kick_sync_xxxxxx_cdr_sync 9 times from 592 (and 7 other PIDs)
> (line 754)
> May 18 13:27:01 db Bucardo[20569]: MCP Received unknown message
> bucardo_kick_sync_xxxxxx_cdr_sync from 592!
> May 18 13:27:01 db Bucardo[20569]: MCP Could not find controller 21817,
> will create a new one. Kicked is 0
> May 18 13:27:01 db Bucardo[20569]: MCP Checking for existing controllers
> for sync "xxxxxx_cdr_sync"
> May 18 13:27:01 db Bucardo[20569]: MCP Created controller 21835 for sync
> "xxxxxx_cdr_sync". Kick is 0
> May 18 13:27:01 db Bucardo[21835]: CTL Created
> /var/run/bucardo.ctl.sync.xxxxxx_cdr_sync.pid
> May 18 13:27:01 db Bucardo[21835]: CTL New controller for sync
> "xxxxxx_cdr_sync". Herd is "cdr", dbs is "xxxxxx_group". PID=21835
> May 18 13:27:01 db Bucardo[21835]: CTL stayalive: 1 checksecs: 0
> limitdbs: 0 kicked: 0
> May 18 13:27:01 db Bucardo[21835]: CTL kidsalive: 1 onetimecopy: 0
> lifetimesecs: 0 (NULL) maxkicks: 0
> May 18 13:27:01 db Bucardo[21835]: CTL Bucardo database backend PID: 21836
> May 18 13:27:01 db Bucardo[21835]: CTL LISTEN for "bucardo_ctl" on
> "bucardo" (line 1244)
> May 18 13:27:01 db Bucardo[21835]: CTL Sending NOTIFY
> "kid_stopsync_xxxxxx_cdr_sync" (line 1284)
> May 18 13:27:01 db Bucardo[21835]: CTL Sending NOTIFY
> "ctl_stopsync_xxxxxx_cdr_sync" (line 1286)
> May 18 13:27:01 db Bucardo[21835]: CTL Connected to database "xxxxxx"
> with backe
>

-- 
Alex Balashov - Principal
Evariste Systems LLC
260 Peachtree Street NW
Suite 2200
Atlanta, GA 30303
Tel: +1-678-954-0670
Fax: +1-404-961-1892
Web: http://www.evaristesys.com/