On 2013-09-03 06:15, Greg Sabino Mullane wrote:
On Mon, Sep 02, 2013 at 03:06:35PM +0200, Christian Ritter wrote:
BUCARDO_ID | id | host_ip | prüfsumme
------------+----+-------------+-----------
1 | 1 | 192.168.1.1 | foobar
(1 row)
(Good debugging so far everyone!)
I would guess that the list of columns as returned from
fetchall_hashref does not match the list stored in $g->{cols}.
Certainly that would explain the behavior. I have not been able
to duplicate the problem on 4.5.0. Could you try adding these
lines to your Bucardo.pm and see what they spit out when you
add a new row to one side?:
diff --git a/Bucardo.pm b/Bucardo.pm
index b303fcd..7c72f61 100644
--- a/Bucardo.pm
+++ b/Bucardo.pm
@@ -5741,6 +5741,9 @@ sub start_kid {
my (@srcrow,@tgtrow);
if ($action & 1 or $action & 4) { ## source to
target / source to source
@srcrow =
@{$info1->{$pkval}}{@{$g->{cols}}};
+ warn Dumper $info1;
+ warn Dumper $g->{cols};
+ warn Dumper \@srcrow;
}
if ($action & 2 or $action & 8) { ## target to
source / target to target
@tgtrow =
@{$info2->{$pkval}}{@{$g->{cols}}};
Hi Greg,
i patched Bucardo.pm and here is the output:
$BUCARDO1 = {
'1' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '1',
"pr\x{fc}fsumme" => 'foobar',
'id' => 1,
'host_ip' => '192.168.1.1'
},
'2' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '2',
"pr\x{fc}fsumme" => 'foobar',
'id' => 2,
'host_ip' => '192.168.1.2'
}
};
$BUCARDO1 = [
'host_ip',
'prüfsumme'
];
$BUCARDO1 = [
'192.168.1.1',
undef
];
[Tue Sep 3 08:10:22 2013] KID [1/2] public.testtable INSERT source to
target pk 1
[Tue Sep 3 08:10:22 2013] KID Warning! Aborting due to exception for
public.testtable.id: 1 Error was DBD::Pg::st execute failed: ERROR:
null value in column "prüfsumme" violates not-null constraint at
/root/perl5/lib/perl5/Bucardo.pm line 5772.
The Full Log is attached to this mail.
Cheers
Christian
[Tue Sep 3 08:10:20 2013] MCP Starting Bucardo version 4.5.0
[Tue Sep 3 08:10:20 2013] MCP Local system epoch: 1378188620 Database epoch:
1378188620.73787
[Tue Sep 3 08:10:20 2013] MCP Local system time: Tue Sep 3 08:10:20 2013
Database time: 2013-09-03 08:10:20.737875+02
[Tue Sep 3 08:10:20 2013] MCP Local system timezone: CEST Database timezone:
localtime
[Tue Sep 3 08:10:20 2013] MCP PID: 16881
[Tue Sep 3 08:10:20 2013] MCP Backend PID: 16882
[Tue Sep 3 08:10:20 2013] MCP Postgres library version: 90103
[Tue Sep 3 08:10:20 2013] MCP bucardo_ctl: /root/perl5/bin/bucardo_ctl
[Tue Sep 3 08:10:20 2013] MCP Bucardo.pm: /root/perl5/lib/perl5/Bucardo.pm
[Tue Sep 3 08:10:20 2013] MCP OS: linux Perl: /usr/bin/perl 5.14.2
[Tue Sep 3 08:10:20 2013] MCP DBI version: 1.616 DBD::Pg version: 2.19.0
[Tue Sep 3 08:10:20 2013] MCP Bucardo object:
bcverbose => '1'
cleandebugs => '0'
created => 'Tue Sep 3 08:10:18 2013'
dbhost => 'localhost'
dbname => 'bucardo'
dbpass => '<not shown>'
dbport => '5432'
dbuser => 'bucardo'
debugdir => '.'
debugfile => '1'
debugfilehandle => 'HASH(0x2c8c2c0)'
debugfilename => './log.bucardo'
debugfilesep => '0'
debugname => ''
debugsyslog => '1'
dryrun => '0'
extraname => ''
logprefix => 'MCP'
masterdbh => 'DBI::db=HASH(0x3252a50)'
mcp_clock_timestamp => 'clock_timestamp()'
pidfile => '/var/run/bucardo/bucardo.mcp.pid'
ppid => '16877'
sendmail => '0'
sendmail_file => ''
stopfile => '/var/run/bucardo/fullstopbucardo'
verbose => '1'
version => '4.5.0'
warning_file => '/var/local/bucardo/warning.log'
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_mcp_fullstop"
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_mcp_reload"
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_reload_config"
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_log_message"
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_mcp_ping"
[Tue Sep 3 08:10:20 2013] MCP Listening for
"bucardo_deactivate_sync_test_sync"
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_reload_sync_test_sync"
[Tue Sep 3 08:10:20 2013] MCP Listening for "bucardo_kick_sync_test_sync"
[Tue Sep 3 08:10:21 2013] MCP LOADING TABLE sync. Rows=1
[Tue Sep 3 08:10:21 2013] MCP Entries cleaned from the q table: 1
[Tue Sep 3 08:10:21 2013] MCP Activating sync "test_sync"
[Tue Sep 3 08:10:21 2013] MCP Running validate_sync on "test_sync"
[Tue Sep 3 08:10:21 2013] MCP Source database backend PID is 16885
[Tue Sep 3 08:10:21 2013] MCP Connecting to target database "testb"
[Tue Sep 3 08:10:21 2013] MCP Target database backend PID is 16886
[Tue Sep 3 08:10:21 2013] MCP Inspecting source table public.testtable on
database "testa"
[Tue Sep 3 08:10:21 2013] MCP Standard conflict method "latest" chosen
[Tue Sep 3 08:10:21 2013] MCP Checking column on target database "testb":
"host_ip" (inet)
[Tue Sep 3 08:10:21 2013] MCP Checking column on target database "testb":
"id" (integer)
[Tue Sep 3 08:10:21 2013] MCP Checking column on target database "testb":
"prüfsumme" (character varying(255))
[Tue Sep 3 08:10:21 2013] MCP Listening on source server "testa" for
"bucardo_kick_sync_test_sync"
[Tue Sep 3 08:10:21 2013] MCP Listening on remote server testb for
"bucardo_kick_sync_test_sync"
[Tue Sep 3 08:10:21 2013] MCP Active syncs: 1
[Tue Sep 3 08:10:21 2013] MCP Entering main loop
[Tue Sep 3 08:10:21 2013] MCP Checking for existing controllers for sync
"test_sync"
[Tue Sep 3 08:10:21 2013] MCP Created controller 16887 for sync "test_sync".
Kick is 1
[Tue Sep 3 08:10:21 2013] CTL Controller starting for sync "test_sync".
Source herd is "test_herd"
[Tue Sep 3 08:10:21 2013] CTL PID: 16887
[Tue Sep 3 08:10:21 2013] CTL database: testb synctype: swap stayalive: 1
checksecs: 0
[Tue Sep 3 08:10:21 2013] CTL limitdbs: 0 kicked: 1 kidsalive: 1
onetimecopy: 0
[Tue Sep 3 08:10:21 2013] CTL lifetimesecs: 0 (<NULL>) maxkicks: 0
[Tue Sep 3 08:10:21 2013] CTL Bucardo database backend PID is 16888
[Tue Sep 3 08:10:21 2013] CTL Listening for "bucardo_ctl_kick_test_sync"
[Tue Sep 3 08:10:21 2013] CTL Herd member 28039: public.testtable
[Tue Sep 3 08:10:21 2013] CTL Target oids: testb:28047
[Tue Sep 3 08:10:21 2013] CTL Cleaning out old q entry. sync='test_sync'
pid=14843 ppid=14709 targetdb=testb started:1 ended:0 aborted:1
cdate=2013-09-02 13:23:12.472676+02
[Tue Sep 3 08:10:21 2013] CTL Created new kid 16889 for sync "test_sync" to
database "testb"
[Tue Sep 3 08:10:21 2013] KID New kid, syncs "testa" to "testb" for sync
"test_sync" alive=1 Parent=16887 Type=swap
[Tue Sep 3 08:10:21 2013] KID PID: 16889
[Tue Sep 3 08:10:21 2013] KID Bucardo database backend PID is 16890
[Tue Sep 3 08:10:21 2013] KID Source database backend PID is 16891
[Tue Sep 3 08:10:21 2013] KID Target database backend PID is 16892
[Tue Sep 3 08:10:21 2013] KID Source backend PID: 16891. Target backend PID:
16892
[Tue Sep 3 08:10:21 2013] KID Nothing to do: no entry found in the q table
for this sync
[Tue Sep 3 08:10:22 2013] KID Got a notice for test_sync: testa -> testb
[Tue Sep 3 08:10:22 2013] KID Source delta count for public.testtable: 2
[Tue Sep 3 08:10:22 2013] KID Target delta count for public.testtable: 0
[Tue Sep 3 08:10:22 2013] KID Total source delta count: 2
[Tue Sep 3 08:10:22 2013] KID Total target delta count: 0
[Tue Sep 3 08:10:22 2013] KID Total delta count: 2
[Tue Sep 3 08:10:22 2013] KID No conflict, source only for
public.testtable.id: 1
[Tue Sep 3 08:10:22 2013] KID No conflict, source only for
public.testtable.id: 2
[Tue Sep 3 08:10:22 2013] KID Action summary: 1:2
$BUCARDO1 = {
'1' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '1',
"pr\x{fc}fsumme" => 'foobar',
'id' => 1,
'host_ip' => '192.168.1.1'
},
'2' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '2',
"pr\x{fc}fsumme" => 'foobar',
'id' => 2,
'host_ip' => '192.168.1.2'
}
};
$BUCARDO1 = [
'host_ip',
'prüfsumme'
];
$BUCARDO1 = [
'192.168.1.1',
undef
];
[Tue Sep 3 08:10:22 2013] KID [1/2] public.testtable INSERT source to target
pk 1
[Tue Sep 3 08:10:22 2013] KID Warning! Aborting due to exception for
public.testtable.id: 1 Error was DBD::Pg::st execute failed: ERROR: null value
in column "prüfsumme" violates not-null constraint at
/root/perl5/lib/perl5/Bucardo.pm line 5772.
[Tue Sep 3 08:10:22 2013] KID Final database backend PID is 16893
[Tue Sep 3 08:10:22 2013] KID Kid exiting at cleanup_kid. Reason: Died at
/root/perl5/lib/perl5/Bucardo.pm line 5838.
[Tue Sep 3 08:10:22 2013] KID Removed pid file
"/var/run/bucardo/bucardo.kid.sync.test_sync.testb.pid"
[Tue Sep 3 08:10:31 2013] CTL Rows updated child 16889 to aborted in q: 1
[Tue Sep 3 08:10:31 2013] CTL Warning! Kid 16889 seems to have died. Sync
"test_sync"
[Tue Sep 3 08:10:34 2013] MCP Got notice "bucardo_kick_sync_test_sync" from
16923 on database testa
[Tue Sep 3 08:10:34 2013] MCP Sent a kick request to controller 16887 for
sync "test_sync"
[Tue Sep 3 08:10:34 2013] CTL Got notice "bucardo_ctl_kick_test_sync" from
16882
[Tue Sep 3 08:10:34 2013] CTL Creating a kid
[Tue Sep 3 08:10:34 2013] CTL Created new kid 16924 for sync "test_sync" to
database "testb"
[Tue Sep 3 08:10:34 2013] KID New kid, syncs "testa" to "testb" for sync
"test_sync" alive=1 Parent=16887 Type=swap
[Tue Sep 3 08:10:34 2013] KID PID: 16924
[Tue Sep 3 08:10:34 2013] KID Bucardo database backend PID is 16925
[Tue Sep 3 08:10:34 2013] KID Source database backend PID is 16926
[Tue Sep 3 08:10:34 2013] KID Target database backend PID is 16927
[Tue Sep 3 08:10:34 2013] KID Source backend PID: 16926. Target backend PID:
16927
[Tue Sep 3 08:10:34 2013] KID Source delta count for public.testtable: 3
[Tue Sep 3 08:10:34 2013] KID Target delta count for public.testtable: 0
[Tue Sep 3 08:10:34 2013] KID Total source delta count: 3
[Tue Sep 3 08:10:34 2013] KID Total target delta count: 0
[Tue Sep 3 08:10:34 2013] KID Total delta count: 3
[Tue Sep 3 08:10:34 2013] KID No conflict, source only for
public.testtable.id: 1
[Tue Sep 3 08:10:34 2013] KID No conflict, source only for
public.testtable.id: 2
[Tue Sep 3 08:10:34 2013] KID No conflict, source only for
public.testtable.id: 3
[Tue Sep 3 08:10:34 2013] KID Action summary: 1:3
$BUCARDO1 = {
'1' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '1',
"pr\x{fc}fsumme" => 'foobar',
'id' => 1,
'host_ip' => '192.168.1.1'
},
'3' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '3',
"pr\x{fc}fsumme" => 'foobar',
'id' => 3,
'host_ip' => '192.168.1.3'
},
'2' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '2',
"pr\x{fc}fsumme" => 'foobar',
'id' => 2,
'host_ip' => '192.168.1.2'
}
};
$BUCARDO1 = [
'host_ip',
'prüfsumme'
];
$BUCARDO1 = [
'192.168.1.1',
undef
];
[Tue Sep 3 08:10:34 2013] KID [1/3] public.testtable INSERT source to target
pk 1
[Tue Sep 3 08:10:34 2013] KID Warning! Aborting due to exception for
public.testtable.id: 1 Error was DBD::Pg::st execute failed: ERROR: null value
in column "prüfsumme" violates not-null constraint at
/root/perl5/lib/perl5/Bucardo.pm line 5772.
[Tue Sep 3 08:10:34 2013] KID Final database backend PID is 16928
[Tue Sep 3 08:10:34 2013] KID Kid exiting at cleanup_kid. Reason: Died at
/root/perl5/lib/perl5/Bucardo.pm line 5838.
[Tue Sep 3 08:10:34 2013] KID Removed pid file
"/var/run/bucardo/bucardo.kid.sync.test_sync.testb.pid"
[Tue Sep 3 08:10:41 2013] CTL Rows updated child 16924 to aborted in q: 1
[Tue Sep 3 08:10:41 2013] CTL Warning! Kid 16924 seems to have died. Sync
"test_sync"
[Tue Sep 3 08:10:52 2013] CTL Cleaning up aborted sync from q table for
"testb". PID was 16924
[Tue Sep 3 08:10:52 2013] CTL Re-adding sync to q table for database "testb"
[Tue Sep 3 08:10:53 2013] CTL Creating kid to handle resurrected q row
[Tue Sep 3 08:10:53 2013] CTL Created new kid 16947 for sync "test_sync" to
database "testb"
[Tue Sep 3 08:10:53 2013] KID New kid, syncs "testa" to "testb" for sync
"test_sync" alive=1 Parent=16887 Type=swap
[Tue Sep 3 08:10:53 2013] KID PID: 16947
[Tue Sep 3 08:10:53 2013] KID Bucardo database backend PID is 16948
[Tue Sep 3 08:10:53 2013] KID Source database backend PID is 16949
[Tue Sep 3 08:10:53 2013] KID Target database backend PID is 16950
[Tue Sep 3 08:10:53 2013] KID Source backend PID: 16949. Target backend PID:
16950
[Tue Sep 3 08:10:53 2013] KID Source delta count for public.testtable: 3
[Tue Sep 3 08:10:53 2013] KID Target delta count for public.testtable: 0
[Tue Sep 3 08:10:53 2013] KID Total source delta count: 3
[Tue Sep 3 08:10:53 2013] KID Total target delta count: 0
[Tue Sep 3 08:10:53 2013] KID Total delta count: 3
[Tue Sep 3 08:10:53 2013] KID No conflict, source only for
public.testtable.id: 1
[Tue Sep 3 08:10:53 2013] KID No conflict, source only for
public.testtable.id: 2
[Tue Sep 3 08:10:53 2013] KID No conflict, source only for
public.testtable.id: 3
[Tue Sep 3 08:10:53 2013] KID Action summary: 1:3
$BUCARDO1 = {
'1' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '1',
"pr\x{fc}fsumme" => 'foobar',
'id' => 1,
'host_ip' => '192.168.1.1'
},
'3' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '3',
"pr\x{fc}fsumme" => 'foobar',
'id' => 3,
'host_ip' => '192.168.1.3'
},
'2' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '2',
"pr\x{fc}fsumme" => 'foobar',
'id' => 2,
'host_ip' => '192.168.1.2'
}
};
$BUCARDO1 = [
'host_ip',
'prüfsumme'
];
$BUCARDO1 = [
'192.168.1.1',
undef
];
[Tue Sep 3 08:10:53 2013] KID [1/3] public.testtable INSERT source to target
pk 1
[Tue Sep 3 08:10:53 2013] KID Warning! Aborting due to exception for
public.testtable.id: 1 Error was DBD::Pg::st execute failed: ERROR: null value
in column "prüfsumme" violates not-null constraint at
/root/perl5/lib/perl5/Bucardo.pm line 5772.
[Tue Sep 3 08:10:53 2013] KID Final database backend PID is 16951
[Tue Sep 3 08:10:53 2013] KID Kid exiting at cleanup_kid. Reason: Died at
/root/perl5/lib/perl5/Bucardo.pm line 5838.
[Tue Sep 3 08:10:53 2013] KID Removed pid file
"/var/run/bucardo/bucardo.kid.sync.test_sync.testb.pid"
[Tue Sep 3 08:11:01 2013] CTL Warning! Kid 16947 seems to have died. Sync
"test_sync"
[Tue Sep 3 08:11:23 2013] CTL Cleaning up aborted sync from q table for
"testb". PID was 16947
[Tue Sep 3 08:11:23 2013] CTL Re-adding sync to q table for database "testb"
[Tue Sep 3 08:11:24 2013] CTL Creating kid to handle resurrected q row
[Tue Sep 3 08:11:24 2013] CTL Created new kid 16976 for sync "test_sync" to
database "testb"
[Tue Sep 3 08:11:24 2013] KID New kid, syncs "testa" to "testb" for sync
"test_sync" alive=1 Parent=16887 Type=swap
[Tue Sep 3 08:11:24 2013] KID PID: 16976
[Tue Sep 3 08:11:24 2013] KID Bucardo database backend PID is 16977
[Tue Sep 3 08:11:24 2013] KID Source database backend PID is 16978
[Tue Sep 3 08:11:24 2013] KID Target database backend PID is 16979
[Tue Sep 3 08:11:24 2013] KID Source backend PID: 16978. Target backend PID:
16979
[Tue Sep 3 08:11:24 2013] KID Source delta count for public.testtable: 3
[Tue Sep 3 08:11:24 2013] KID Target delta count for public.testtable: 0
[Tue Sep 3 08:11:24 2013] KID Total source delta count: 3
[Tue Sep 3 08:11:24 2013] KID Total target delta count: 0
[Tue Sep 3 08:11:24 2013] KID Total delta count: 3
[Tue Sep 3 08:11:24 2013] KID No conflict, source only for
public.testtable.id: 1
[Tue Sep 3 08:11:24 2013] KID No conflict, source only for
public.testtable.id: 2
[Tue Sep 3 08:11:24 2013] KID No conflict, source only for
public.testtable.id: 3
[Tue Sep 3 08:11:24 2013] KID Action summary: 1:3
$BUCARDO1 = {
'1' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '1',
"pr\x{fc}fsumme" => 'foobar',
'id' => 1,
'host_ip' => '192.168.1.1'
},
'3' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '3',
"pr\x{fc}fsumme" => 'foobar',
'id' => 3,
'host_ip' => '192.168.1.3'
},
'2' => {
'BUCARDO_ACTION' => 1,
'BUCARDO_ID' => '2',
"pr\x{fc}fsumme" => 'foobar',
'id' => 2,
'host_ip' => '192.168.1.2'
}
};
$BUCARDO1 = [
'host_ip',
'prüfsumme'
];
$BUCARDO1 = [
'192.168.1.1',
undef
];
[Tue Sep 3 08:11:24 2013] KID [1/3] public.testtable INSERT source to target
pk 1
[Tue Sep 3 08:11:24 2013] KID Warning! Aborting due to exception for
public.testtable.id: 1 Error was DBD::Pg::st execute failed: ERROR: null value
in column "prüfsumme" violates not-null constraint at
/root/perl5/lib/perl5/Bucardo.pm line 5772.
[Tue Sep 3 08:11:24 2013] KID Final database backend PID is 16980
[Tue Sep 3 08:11:24 2013] KID Kid exiting at cleanup_kid. Reason: Died at
/root/perl5/lib/perl5/Bucardo.pm line 5838.
[Tue Sep 3 08:11:24 2013] KID Removed pid file
"/var/run/bucardo/bucardo.kid.sync.test_sync.testb.pid"
[Tue Sep 3 08:11:31 2013] CTL Warning! Kid 16976 seems to have died. Sync
"test_sync"
_______________________________________________
Bucardo-general mailing list
[email protected]
https://mail.endcrypt.com/mailman/listinfo/bucardo-general
