[Bucardo-general] Replication won't start.
Don St. Denis
donald.stdenis at goodsearch.com
Wed Jan 11 21:33:59 UTC 2017
Hi,
OK, I got past the table addition problem by specifying the relgroup and
I have added all the Primary Keys required but I am running into an
error that doesn't appear to have much online for:
bucardo at pg1:~$ DBUSER=bucardo DBPASS=*** bucardo add sync the_sync relgroup=copying_herd dbs=source_db:source,dest_db:target onetimecopy=2
WARNING: Issuing rollback() due to DESTROY without explicit disconnect() of DBD::Pg::db handle dbname=good_rails_production at -e line 56.
Failed to add sync: DBD::Pg::st execute failed: ERROR: DBD::Pg::db do failed: ERROR: role "bucardo" already exists at line 186. at line 30.
CONTEXT: PL/Perl function "validate_sync" at /usr/local/bin/bucardo line 4633.
In the Log file I see this:
2017-01-11 21:00:55.653 UTC [00000] [29258]: [1] db=[unknown],user=[unknown],host=[local] LOG: connection received: host=[local]
2017-01-11 21:00:55.654 UTC [00000] [29258]: [2] db=bucardo,user=bucardo,host=[local] LOG: connection authorized: user=bucardo database=bucardo
2017-01-11 21:00:55.724 UTC [00000] [29258]: [3] db=bucardo,user=bucardo,host=[local] LOG: Starting validate_sync for the_sync
2017-01-11 21:00:55.724 UTC [00000] [29258]: [4] db=bucardo,user=bucardo,host=[local] CONTEXT: PL/Perl function "validate_sync"
SQL statement "SELECT validate_sync('the_sync')"
PL/Perl function "validate_sync"
2017-01-11 21:00:55.724 UTC [00000] [29258]: [5] db=bucardo,user=bucardo,host=[local] STATEMENT: INSERT INTO bucardo.sync (name,dbs,herd,onetimecopy) VALUES ($1,$2,$3,$4)
2017-01-11 21:00:56.319 UTC [00000] [29259]: [1] db=[unknown],user=[unknown],host=[local] LOG: connection received: host=[local]
2017-01-11 21:00:56.320 UTC [00000] [29259]: [2] db=good_rails_production,user=bucardo,host=[local] LOG: provided user name (bucardo) and authenticated user name (postgres) do not match
2017-01-11 21:00:56.320 UTC [28000] [29259]: [3] db=good_rails_production,user=bucardo,host=[local] FATAL: Peer authentication failed for user "bucardo"
2017-01-11 21:00:56.320 UTC [28000] [29259]: [4] db=good_rails_production,user=bucardo,host=[local] DETAIL: Connection matched pg_hba.conf line 29: "local all bucardo ident"
2017-01-11 21:00:56.321 UTC [00000] [29260]: [1] db=[unknown],user=[unknown],host=[local] LOG: connection received: host=[local]
2017-01-11 21:00:56.322 UTC [00000] [29260]: [2] db=good_rails_production,user=postgres,host=[local] LOG: connection authorized: user=postgres database=good_rails_production
2017-01-11 21:00:56.323 UTC [00000] [29260]: [3] db=good_rails_production,user=postgres,host=[local] LOG: statement: CREATE USER bucardo SUPERUSER
2017-01-11 21:00:56.323 UTC [42710] [29260]: [4] db=good_rails_production,user=postgres,host=[local] ERROR: role "bucardo" already exists
2017-01-11 21:00:56.323 UTC [42710] [29260]: [5] db=good_rails_production,user=postgres,host=[local] STATEMENT: CREATE USER bucardo SUPERUSER
2017-01-11 21:00:56.323 UTC [01000] [29258]: [6] db=bucardo,user=bucardo,host=[local] WARNING: Issuing rollback() due to DESTROY without explicit disconnect() of DBD::Pg::db handle dbname=good_rails_production at -e line 56.
2017-01-11 21:00:56.323 UTC [01000] [29258]: [7] db=bucardo,user=bucardo,host=[local] CONTEXT: PL/Perl function "validate_sync"
SQL statement "SELECT validate_sync('the_sync')"
PL/Perl function "validate_sync"
2017-01-11 21:00:56.323 UTC [00000] [29260]: [6] db=good_rails_production,user=postgres,host=[local] LOG: disconnection: session time: 0:00:00.002 user=postgres database=good_rails_production host=[local]
2017-01-11 21:00:56.325 UTC [38000] [29258]: [8] db=bucardo,user=bucardo,host=[local] ERROR: DBD::Pg::db do failed: ERROR: role "bucardo" already exists at line 186. at line 30.
2017-01-11 21:00:56.325 UTC [38000] [29258]: [9] db=bucardo,user=bucardo,host=[local] CONTEXT: PL/Perl function "validate_sync"
2017-01-11 21:00:56.325 UTC [38000] [29258]: [10] db=bucardo,user=bucardo,host=[local] STATEMENT: INSERT INTO bucardo.sync (name,dbs,herd,onetimecopy) VALUES ($1,$2,$3,$4)
2017-01-11 21:00:56.326 UTC [00000] [29258]: [11] db=bucardo,user=bucardo,host=[local] LOG: disconnection: session time: 0:00:00.673 user=bucardo database=bucardo host=[local]
Specifically this is weird: "
LOG: provided user name (bucardo) and authenticated user name (postgres) do not match
"
But it clearly matches line 29 authentication below it?
Why does the system try to recreate user bucardo?
Any ideas?
Don.
On 01/10/2017 11:35 AM, Donald StDenis wrote:
> Hi,
>
> I finally got back to this project... Used github to get latest from
> master, ran the perl make, make, and make test (almost all succeeded,
> couple of them failed) then installed it. Then ran through the above
> installation again. Fails same way.
>
> Its been a while since I debugged PERL but the PERL does not seem to
> be the issue here...
>
> I have never debugged Postgres stored procedures/functions BEFORE -
> but I see quite a few in the schema file. Which one would be the most
> interesting to add logging lines to to debug?
>
> I checked the master database carefully there are no entries put into
> the Postgres log file when the sync is added.
>
> Nothing appears to STDOUT or STDERR.
>
> Is there a suggested debugging process I can follow to move forward here?
>
> On Mon, Dec 19, 2016 at 2:00 PM, Donald StDenis
> <donald.stdenis at goodsearch.com <mailto:donald.stdenis at goodsearch.com>>
> wrote:
>
> Here’s the output from the command lines, I don’t see any errors
> or warnings in the database log file. Earlier I tried the —debug
> options on the start and saw no differences. Also previously
> (about 6 months ago while testing with 9.2->9.2 replication) I
> always got errors for trying to add tables without any UNIQUE or
> PRIMARY KEYS but there is none now.
>
> Current output:
>
> bucardo at ale-pg1:~$ echo "DROP DATABASE good_rails_production" |
> psql bucardo
> bucardo at ale-pg1:~$ pg_dump --host=10.223.160.229
> --dbname=good_rails_production --user=bucardo --schema-only
> --create --format=plain > schema-all.sql
> bucardo at ale-pg1:~$ echo "
> CREATE USER conn*** WITH LOGIN SUPERUSER ENCRYPTED PASSWORD '***';
> CREATE USER repo*** WITH LOGIN ENCRYPTED PASSWORD '***';
> " | psql bucardo
> ERROR: role "conn***" already exists
> ERROR: role "repo***" already exists
> bucardo at ale-pg1:~$ psql --dbname=postgres --user=bucardo -f
> schema-all.sql
> <completes without error... very long>
>
> bucardo at ale-pg1:~$ bucardo add db source_db dbhost=10.223.160.229
> dbport=5432 dbname=good_rails_production dbuser=bucardo dbpass=****
> Added database "source_db"
> bucardo at ale-pg1:~$ bucardo add db dest_db
> dbname=good_rails_production dbuser=bucardo
> Added database "dest_db"
> bucardo at ale-pg1:~$ bucardo add all tables
> New tables added: 275
> bucardo at ale-pg1:~$ bucardo add all sequences
> New sequences added: 99
> bucardo at ale-pg1:~$ bucardo add herd copying_herd
> Created relgroup "copying_herd"
> bucardo at ale-pg1:~$ bucardo add sync the_sync relgroup=copying_herd
> dbs=source_db:source,dest_db:target onetimecopy=2
> WARNING: Relgroup has no members: copying_herd
> Added sync "the_sync"
> Created a new dbgroup named "the_sync"
>
> bucardo at ale-pg1:~$ bucardo start
> Checking for existing processes
> Removing file "/var/run/bucardo/fullstopbucardo"
> Starting Bucardo
> bucardo at ale-pg1:~$ bucardo status
> PID of Bucardo MCP: 28741
> Name State Last good Time Last I/D Last bad Time
> ==========+========+============+=======+===========+===========+=======
> the_sync | Bad | none | | | 16:48:44 | 3s
> bucardo at ale-pg1:~$ bucardo status the_sync
> ======================================================================
> Use of uninitialized value $sourcedb in concatenation (.) or
> string at /usr/bin/bucardo line 6013.
> Last bad : Dec 19, 2016 16:48:44 (time until fail: 1s)
> Sync name : the_sync
> Current state : Bad
> Source relgroup/database : copying_herd /
> Tables in sync : 0
> Status : Active
> Check time : None
> Overdue time : 00:00:00
> Expired time : 00:00:00
> Stayalive/Kidsalive : Yes / Yes
> Rebuild index : No
> Autokick : Yes
> Onetimecopy : No
> Post-copy analyze : Yes
> Last error: : Failed : DBD::Pg::st execute failed:
> ERROR: schema "bucardo" does not exist LINE 1: ...ident(tname),
> MAX(EXTRACT(epoch FROM cdate)) FROM bucardo.bu... ^ at /usr/sh\
> are/perl5/Bucardo.pm line 3299. Line: 5041 Main DB state: ? Error:
> none DB dest_db state: ? Error: none DB source_db state: 3F000
> Error: 7 (KID 28752)
> ======================================================================
> bucardo at ale-pg1:~$ bucardo stop
> Creating /var/run/bucardo/fullstopbucardo ... Done
>
>
>
>> On Dec 19, 2016, at 1:49 PM, David Christensen
>> <david at endpoint.com <mailto:david at endpoint.com>> wrote:
>>
>>
>>> On Dec 19, 2016, at 11:06 AM, Donald StDenis
>>> <donald.stdenis at goodsearch.com
>>> <mailto:donald.stdenis at goodsearch.com>> wrote:
>>>
>>> Hi,
>>>
>>> I’ve been trying to set up Bucardo replication from Pg9.2 to
>>> Pg9.6 and I can’t seem to make the replication start.
>>>
>>> I did this from 9.2->9.2 about 6 months ago with almost no
>>> problems as I recall.
>>>
>>> The bucardo status error on the slave is:
>>>
>>> bacardi:~$ bucardo status
>>
>> [snip]
>>
>> Hi Donald,
>>
>> If it’s not finding the “bucardo” schema, that would indicate
>> that the “validate_sync()” step did not complete successfully
>> when you did an `bucardo add sync …`. Do you have logs of the
>> steps for setting this up and any errors encountered in that process?
>>
>> Best,
>>
>> David
>> --
>> David Christensen
>> End Point Corporation
>> david at endpoint.com <mailto:david at endpoint.com>
>> 785-727-1171 <tel:%28785%29%20727-1171>
>>
>>
>>
>
>
>
>
> --
> --
> *Donald St. Denis*
> DevOps Engineer
> /donald.stdenis at goodsearch.com <mailto:donald.stdenis at goodsearch.com>/
> /707-331-9624/
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.endcrypt.com/pipermail/bucardo-general/attachments/20170111/ddf4e5a0/attachment-0001.html>
More information about the Bucardo-general
mailing list