[Bucardo-general] Problem with custom code not being called

[hubert depesz lubaczewski]

Hi,
I'm trying to write custom conflict handler.

Installed bucardo 5.6 on pg 9.5 (yes, I know, it's old, we are in
process of developing migration path).

Created very simple db with 2 tables (users, other), copied the db, and
then setup bucardo:

bucardo install --piddir=/home/pgtest/tmp
bucardo add db src dbname=pgtest port=5950 host=127.0.0.1
bucardo add db dest dbname=pgtest port=5951 host=127.0.0.1
bucardo add relgroup spublic
bucardo add dbgroup spublic src:source dest:target
bucardo add sync spublic relgroup=spublic dbgroup=spublic strict_checking=false
bucardo add table public.users relgroup=spublic db=src strict_checking=false
bucardo add table public.other relgroup=spublic db=src strict_checking=false
bucardo validate spublic
bucardo update sync spublic onetimecopy=2
bucardo stop
bucardo start
bucardo update dbgroup spublic src:source dest:source
bucardo validate spublic
bucardo status spublic
bucardo stop
bucardo start

This rather complex process is because I'm trying to emulate existing script in my test env.

Anyway - at the end of the process I have working bi-directional replication.

Then, I tried to add customcode.

To be able to understand how to do it, I need to know what is in $info
argument, so I wrote "conflict.pl" with this code:

#v+
use strict;
use warnings;
use Data::Dumper;
my $info = shift;
open my $fh, '>>', '/tmp/debug.log';
print $fh Dumper($info);
close $fh;
return;
#v-

afterwards did:

bucardo add customcode ctest whenrun=conflict src_code=conflict.pl sync=spublic
bucardo reload sync spublic

Even did stop/start.

And - code is not being run, or, at least - /tmp/debug.log is not created.

TO be sure, I removed all rows, ran clean syncs, and then added conflicting rows, and ran
bucardo kick spublic.

Logs show:

(1743120) [Wed Apr  1 17:30:46 2020] KID (spublic) Warning! Aborting due to exception for public.users:? Error was DBD::Pg::db pg_putcopyend failed: ERROR:  duplicate key value violates unique constraint "users_username_key"\nDETAIL:  Key (username)=(conflictuser) already exists.\nCONTEXT:  COPY users, line 1 at /home/pgtest/perl5/lib/perl5/Bucardo.pm line 10118.
(1743120) [Wed Apr  1 17:30:46 2020] KID (spublic) Kid has died, error is: DBD::Pg::db pg_putcopyend failed: ERROR:  duplicate key value violates unique constraint "users_username_key"\nDETAIL:  Key (username)=(conflictuser) already exists.\nCONTEXT:  COPY users, line 1 at /home/pgtest/perl5/lib/perl5/Bucardo.pm line 10118. Line: 5037 Main DB state: ? Error: none DB dest state: ? Error: none DB src state: 23505 Error: 7 
(1743120) [Wed Apr  1 17:30:46 2020] KID (spublic) Kid 1743120 exiting at cleanup_kid. Sync "spublic" public.users Reason: DBD::Pg::db pg_putcopyend failed: ERROR:  duplicate key value violates unique constraint "users_username_key"\nDETAIL:  Key (username)=(conflictuser) already exists.\nCONTEXT:  COPY users, line 1 at /home/pgtest/perl5/lib/perl5/Bucardo.pm line 10118. Line: 5037 Main DB state: ? Error: none DB dest state: ? Error: none DB src state: 23505 Error: 7 
(1708901) [Wed Apr  1 17:30:46 2020] MCP Starting check_sync_health
(1745097) [Wed Apr  1 17:30:48 2020] KID (spublic) New kid, sync "spublic" alive=1 Parent=1708960 PID=1745097 kicked=0 

But there is nothing in /tmp/debug.log.

What am I missing? What did I screw up?

Best regards,

depesz