[Bucardo-general] Make Test Fails
Ben Allen
bsa at lanl.gov
Mon Oct 1 15:36:35 UTC 2007
Greg,
Grep errors from the latest git version:
ok 100 - (sync_methods) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
ok 115 - (bucardo_config) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
ok 170 - (purge) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
ok 227 - (pushdelta) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
ok 336 - (makedelta) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
ok 399 - (fullcopy analyze) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
ok 572 - (swap) Existing Bucardo asked to shut down
/bin/grep: not found
/bin/grep: not found
/bin/grep: not found
I don't see anything to obvious about the error on test 588, but here
is the end of my log.bucardo:
(17791) [1191250717] KID Finished syncing. Time: 0. Updates: 0+1
Inserts: 0+0 Deletes: 0+0 Sync: customcode. Keepalive: 1
(17791) [1191250717] KID Running after_txn custom code 11:
after_txn_test
(17791) [1191250717] KID Finished custom code 11
(17791) [1191250717] KID Message from after_txn code 11: Created
file /tmp/bucardo_test_file.7
(17707) [1191250717] MCP Got notice "bucardo_reload_sync_customcode"
from 17365 on main
(17707) [1191250717] MCP Deactivating sync customcode
(17707) [1191250717] MCP Sent kill 15 to CTL process 17789. Result: 1
(17789) [1191250717] CTL Warning! Controller for "customcode" was
killed at line 269: Caught a SIGTERM at /usr/local/lib/perl5/
site_perl/5.8.8/Bucardo.pm line 2912
(17789) [1191250717] CTL Asking kid process 17791 to terminate
(17789) [1191250717] CTL Controller exiting at cleanup_controller.
Reason: Killed (line 269): Caught a SIGTERM at /usr/local/lib/perl5/
site_perl/5.8.8/Bucardo.pm line 2912
(17791) [1191250717] KID Warning! Child for "customcode" was killed
at line 269: Caught a SIGTERM at /usr/local/lib/perl5/site_perl/5.8.8/
Bucardo.pm line 3625
(17707) [1191250719] MCP Reactivating sync customcode
(17707) [1191250719] MCP Validating custom code 5 (before_txn)
(goat=0): custom code test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 6 (before_txn)
(goat=0): before_txn_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 7
(before_check_rows) (goat=0): before_check_rows_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 8
(before_trigger_drop) (goat=0): before_trigger_drop_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 9
(before_trigger_enable) (goat=0): before_trigger_enable_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 10
(after_trigger_enable) (goat=0): after_trigger_enable_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 11 (after_txn)
(goat=0): after_txn_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating custom code 12 (before_sync)
(goat=0): before_sync_test
(17707) [1191250719] MCP OK: code contains a dummy string
(17707) [1191250719] MCP Validating source table
"bucardo_schema.bucardo_test1" on bctest1
(17707) [1191250719] MCP Comparing tables and columns on bctest2
(17707) [1191250719] MCP Standard conflict method "source" chosen
(17707) [1191250719] MCP Validating source table
"bucardo_schema.bucardo_test2" on bctest1
(17707) [1191250719] MCP Comparing tables and columns on bctest2
(17707) [1191250719] MCP Standard conflict method "source" chosen
(17707) [1191250719] MCP Validating source table
"bucardo_schema.bucardo_test3" on bctest1
(17707) [1191250719] MCP Comparing tables and columns on bctest2
(17707) [1191250719] MCP Standard conflict method "source" chosen
(17707) [1191250719] MCP Validating source table
"bucardo_schema.bucardo_test4" on bctest1
(17707) [1191250719] MCP Comparing tables and columns on bctest2
(17707) [1191250719] MCP Standard conflict method "source" chosen
(17707) [1191250719] MCP Listening on source server bctest1 for
"bucardo_kick_sync_customcode"
(17707) [1191250719] MCP Listening on remote server bctest2 for
"bucardo_kick_sync_customcode"
(17707) [1191250719] MCP Sent notice bucardo_reloaded_sync_customcode
(17707) [1191250719] MCP Checking for existing controllers for sync
"customcode"
(17707) [1191250719] MCP Created controller 17804 for sync
"customcode". Kick is 0
(17804) [1191250719] CTL Controller starting for sync "customcode".
Source herd is "bctestherd1"
(17804) [1191250719] CTL database: bctest2 synctype:swap stayalive:
1 checksecs:0
(17804) [1191250719] CTL limitdbs:0 kicked:0 kidsalive:1 triggers:
pg_class
(17804) [1191250719] CTL Listening for "bucardo_ctl_kick_customcode"
(17804) [1191250719] CTL Herd member 20770:
bucardo_schema.bucardo_test1
(17804) [1191250719] CTL Target oids: bctest2:20779
(17804) [1191250719] CTL Herd member 20803:
bucardo_schema.bucardo_test2
(17804) [1191250719] CTL Target oids: bctest2:20812
(17804) [1191250719] CTL Herd member 20836:
bucardo_schema.bucardo_test3
(17804) [1191250719] CTL Target oids: bctest2:20845
(17804) [1191250719] CTL Herd member 20869:
bucardo_schema.bucardo_test4
(17804) [1191250719] CTL Target oids: bctest2:20878
(17804) [1191250719] CTL Created new kid 17806 for sync "customcode"
(17806) [1191250719] KID New kid, syncs "bctest1" to "bctest2" for
sync "customcode" alive=1 Parent=17804
(17806) [1191250719] KID Nothing to do: no entry found in the q table
for this sync
(17707) [1191250719] MCP Got notice "bucardo_kick_sync_customcode"
from 17367 on db bctest1
(17707) [1191250719] MCP Sent a kick request to controller 17804 for
sync "customcode"
(17804) [1191250721] CTL Got notice "bucardo_ctl_kick_customcode"
from 17708
(17804) [1191250721] CTL Running before_sync controller custom code
12: before_sync_test
(17806) [1191250740] KID Found stopfile "/tmp/bucardo_testing_root/
fullstopbucardo": exiting
(17806) [1191250740] KID Kid exiting
(17707) [1191250740] MCP Found stopfile "/tmp/bucardo_testing_root/
fullstopbucardo": exiting
(17707) [1191250740] MCP Removed file "/tmp/bucardo_testing_root/
bucardo_testing.pid"
(17804) [1191250740] CTL Finished custom code 12
(17804) [1191250740] CTL Message from before_sync code 12: Created
file /tmp/bucardo_test_file.11
(17804) [1191250740] CTL Creating a kid
(17804) [1191250740] CTL Created new kid 17820 for sync "customcode"
(17820) [1191250740] KID New kid, syncs "bctest1" to "bctest2" for
sync "customcode" alive=1 Parent=17804
(17707) [1191250740] MCP End of cleanup_mcp. Sys time: Mon Oct 1
08:59:00 2007. DB time: 2007-10-01 08:59:00.286075-06
(17707) [1191250740] MCP Exiting
(17820) [1191250740] KID Found stopfile "/tmp/bucardo_testing_root/
fullstopbucardo": exiting
(17820) [1191250740] KID Kid exiting
(17804) [1191250741] CTL Found stopfile "/tmp/bucardo_testing_root/
fullstopbucardo": exiting
(17804) [1191250741] CTL Warning! Controller for "customcode" was
killed at line 2542: Found stopfile: Stop the testing
(17804) [1191250741] CTL Controller exiting at cleanup_controller.
Reason: Killed (line 2542): Found stopfile: Stop the testing
Inty 11 isn't in the second database, inty 7 is still there. Inty 11
exists in the first database though.
I'm going to keep trying to dig through this today.
Thanks for your help.
Regards,
Ben
On Sep 28, 2007, at 3:45 PM, Greg Sabino Mullane wrote:
> On Fri, 2007-09-28 at 10:18 -0600, Ben Allen wrote:
>
>> Oh on a side note, your test script looks for grep at /bin/grep, on
>> FreeBSD its located at /usr/bin/grep. As a quick fix for this test I
>> just sym links grep to where the script expects it.
>
> Side note first - just pushed a patch for this from Jeff Boes. A
> git-pull should add it in, and it should clear this problem up.
>
>>
>> ok 588 - (customcode) Test file "/tmp/bucardo_test_file.7" was
>> created
>> by 'after_txn' custom code
>> Bail out! Gave up waiting for "SELECT 1 FROM bucardo_test1 WHERE
>> inty
>> = 11" on db "two" to be true: timed out at 20 from line 3009 (Line
>> 896: Line 162: Timed out at t/01bc.t line 162.
>> FAILED--Further testing stopped: Gave up waiting for "SELECT 1 FROM
>> bucardo_test1 WHERE inty = 11" on db "two" to be true: timed out
>> at 20
>> from line 3009 (Line 896: Line 162: Timed out at t/01bc.t line 162.
>> #
>> # Leaving, shutting down any running processes
>> *** Error code 255
>> My environment:
>>
>>
>> Freebsd 6.2 Stable - AMD64
>> Postgresql 8.2.5
>> Perl 5.8.8
>> Bucardo-3.0.6
>>
>> Any ideas, no other errors up until that point?
>
> Not off the top of my head, but the custom_code tests are some of the
> most ornery tests. Does it fail at this part every time? Generally
> what
> I do to debug this is to switch off all the other tests (see the 'our
> $TEST_...' lines at the top of 01bc.t) and then look through the
> log.bucardo file to see if it has any unusual warnings or errors. You
> can also check the second database after it bails to see if inty 11
> ever
> showed up. If it has, then it is a timing issue. If it hasn't, then
> the
> sync failed before it could copy that row for some reason. One can
> further narrow down timing issues by flipping the $showtime
> variable in
> 01bc.t, which will show exactly what time each test output line is
> created, which can be compared to the timestamps in the log file.
>
> Thanks for trying this out, let me know if I can be of more help in
> debugging this.
>
> --
> Greg Sabino Mullane greg at endpoint.com
> End Point Corporation 610-983-9073
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: https://mail.endcrypt.com/pipermail/bucardo-general/attachments/20071001/a079f3ea/attachment.html
More information about the Bucardo-general
mailing list