End syncs on deadlock and serialization failure.

When I added the serialization failure-handling code, I neglected to notice
that it left orphaned `syncrun` rows with no `ended` value. This confused
later syncruns -- like the one that would run after the 0.5s sleep after a
serialization failure. The code was rolling back the main (Bucardo) database
connection, but the syncrun was already committed elsewhere (so that other
processes could see that a sync is in progress, of course; duh!).

So modify the code to instead call `end_syncrun()` and declare the sync
failed, but, of course, with a status recording the seriazliation failure or
deadlock.

diff --git a/Bucardo.pm b/Bucardo.pm
index 839dc03f9e46e3ffbeb635d31a0bef79048c4806..2b4c6f58270d28fb751b0071f53703085fc140bd 100644 (file)
--- a/Bucardo.pm
+++ b/Bucardo.pm
@@ -4765,7 +4765,7 @@ sub start_kid {
         $err_handler->($err) if $err !~ /DBD::Pg/;
 
         ## We only do special things for certain errors, so check for those.
-        my ($sleeptime,$payload_detail) = (0,'');
+        my ($sleeptime, $fail_msg) = (0,'');
         my @states = map { $sync->{db}{$_}{dbh}->state } @dbs_dbi;
         if (first { $_ eq '40001' } @states) {
             $sleeptime = $config{kid_serial_sleep};
@@ -4781,7 +4781,7 @@ sub start_kid {
             else {
                 $self->glog('Could not serialize, will try again', LOG_NORMAL);
             }
-            $payload_detail = "Serialization failure. Sleep=$sleeptime";
+            $fail_msg = "Serialization failure";
         }
         elsif (first { $_ eq '40P01' } @states) {
             $sleeptime = $config{kid_deadlock_sleep};
@@ -4797,7 +4797,7 @@ sub start_kid {
             else {
                 $self->glog('Encountered a deadlock, will try again', LOG_NORMAL);
             }
-            $payload_detail = "Deadlock detected. Sleep=$sleeptime";
+            $fail_msg = "Deadlock detected";
             ## TODO: Get more information via gett_deadlock_details()
         }
         else {
@@ -4810,12 +4810,14 @@ sub start_kid {
             $dbh->pg_cancel if $dbh->{pg_async_status} > 0;
             $dbh->rollback;
         }
-        $maindbh->rollback;
+
+        # End the syncrun.
+        $self->end_syncrun($maindbh, 'bad', $syncname, "Failed : $fail_msg (KID $$)" );
+        $maindbh->commit;
 
         ## Tell listeners we are about to sleep
         ## TODO: Add some sweet payload information: sleep time, which dbs/tables failed, etc.
-        $self->db_notify($maindbh, "syncsleep_${syncname}", 0, $payload_detail);
-        $maindbh->commit;
+        $self->db_notify($maindbh, "syncsleep_${syncname}", 0, "$fail_msg. Sleep=$sleeptime");
 
         ## Sleep and try again.
         sleep $sleeptime if $sleeptime;

diff --git a/t/40-serializable.t b/t/40-serializable.t
index 213864f3c2dd2fb34dab20b628253d3be88e40be..77e5ab177cfbf9c7302eaad72b79b214b60dde78 100644 (file)
--- a/t/40-serializable.t
+++ b/t/40-serializable.t
@@ -11,7 +11,7 @@ my $bct = BucardoTesting->new({location => 'postgres'})
 
 END { $bct->stop_bucardo if $bct }
 
-my $dbh = $bct->connect_database('A');
+my $dbh = $bct->empty_cluster('A');
 END { $dbh->disconnect if $dbh }
 
 # Skip the tests if we can't mock the serialization failure.
@@ -19,7 +19,7 @@ plan skip_all => "Cannot mock serialization failure on Postgres $dbh->{pg_server
     if $dbh->{pg_server_version} < 80400;
 
 # We are a go!
-plan tests => 27;
+plan tests => 45;
 $dbh->disconnect;
 $dbh = undef;
 
@@ -74,7 +74,19 @@ ok $bct->wait_for_notice($dbhX, 'bucardo_syncdone_serialtest1'),
 # Should have no rows.
 $bct->check_for_row([], [qw(A B)], undef, 'test[12]$');
 
+# Make sure the sync was recorded.
+ok my $runs = $dbhX->selectall_arrayref(
+    'SELECT * FROM syncrun ORDER BY started',
+    { Slice => {} },
+), 'Get list of syncruns';
+is @{ $runs }, 1, 'Should have one syncrun';
+ok $runs->[0]{ended}, 'It should have an "ended" value';
+ok $runs->[0]{lastempty}, 'It should be marked "last empty"';
+like $runs->[0]{status}, qr/^No delta rows found/,
+    'Its status should be "No delta rows found"';
+
 # Let's add some data into A.bucardo_test1.
+$dbhX->commit;
 ok $dbhA->do(q{INSERT INTO bucardo_test1 (id, data1) VALUES (1, 'foo')}),
     'Insert a row into test1';
 $dbhA->commit;
@@ -87,7 +99,18 @@ is_deeply $dbhB->selectall_arrayref(
     'SELECT id, data1 FROM bucardo_test1'
 ), [[1, 'foo']], 'Should have the test1 row in B';
 
+# Should have two syncrun records now.
+ok $runs = $dbhX->selectall_arrayref(
+    'SELECT * FROM syncrun ORDER BY started',
+    { Slice => {} },
+), 'Get list of syncruns';
+is @{ $runs }, 2, 'Should have two syncruns';
+ok $runs->[1]{ended}, 'New run should have an "ended" value';
+ok $runs->[1]{lastgood}, 'It should be marked "last good"';
+like $runs->[1]{status}, qr/^Complete/, 'Its status should be "Complete"';
+
 # Excellent. Now let's insert into test2.
+$dbhX->commit;
 ok $dbhA->do(q{INSERT INTO bucardo_test2 (id, data1) VALUES (2, 'foo')}),
     'Insert a row into test2';
 $dbhA->commit;
@@ -101,3 +124,17 @@ ok $bct->wait_for_notice($dbhX, 'bucardo_syncdone_serialtest1'),
 is_deeply $dbhB->selectall_arrayref(
     'SELECT id, data1 FROM bucardo_test2'
 ), [[2, 'foo']], 'Should have the B test2 row despite serialization failure';
+
+# Should have four syncrun records now.
+ok $runs = $dbhX->selectall_arrayref(
+    'SELECT * FROM syncrun ORDER BY started',
+    { Slice => {} },
+), 'Get list of syncruns';
+is @{ $runs }, 4, 'Should have four syncruns';
+ok $runs->[2]{ended}, 'Third run should have an "ended" value';
+ok $runs->[2]{lastbad}, 'Third run should be marked "last bad"';
+like $runs->[2]{status}, qr/^Failed/, 'Third run status should be "Bad"';
+
+ok $runs->[3]{ended}, 'Fourth run should have an "ended" value';
+ok $runs->[3]{lastgood}, 'Fourth run should be marked "last good"';
+like $runs->[3]{status}, qr/^Complete/, 'Fourth run status should be "Complete"';