Thread: erserver 1.2 problem

erserver 1.2 problem

From

Andrew Rawnsley

Date:

28 August 2003, 21:36:14

Downloaded the eRServer 1.2 source (thanks, guys) and installed, and am
having a problem. Anyone else dug into this yet?

Situation:

PG 7.3.4 on linux (master)
Its been tried with 3 slaves, all 7.3.4, 2 on OS X and one on Linux.

It builds fine. It installs fine. I go through the setup with no
problems (calling createlang, doing the initial ers_setup, adding
tables, adding slaves, etc.)

The startup goes fine. No complaints in the log file. It sees every
slave.

Problem is, nothing seems to replicate. I insert records into the
tables on the master and nothing happens. If I am reading the logs
right, it thinks it is:

2003-08-27 17:03:34,563 [Thread-7] INFO replic - Rserv::syncSync: Last
SyncID applied: syncid=27
2003-08-27 17:03:34,568 [Thread-7] INFO replic - Rserv::replicate :
PREPARE SNAPSHOT BEGINS ...
2003-08-27 17:03:34,665 [Thread-7] INFO replic - Rserv::replicate :
PREPARED SNAPSHOT to SERVER 0 IN 102 MILLIS.; Snapshot Got
Something=true
2003-08-27 17:03:34,665 [Thread-7] INFO replic - Rserv::replicate :
APPLY SNAPSHOT BEGINS ...
2003-08-27 17:03:34,675 [Thread-7] INFO replic - Rserv::syncSync: Last
SyncID applied: syncid=30
2003-08-27 17:03:34,692 [Thread-7] INFO replic - Rserv::replicate :
SUCCESSFULLY REPLICATED to SERVER 0 IN 130 MILLIS.; Average time per 1
update=?
2003-08-27 17:03:34,923 [Thread-9] INFO replic - Rserv::syncSync: Last
SyncID applied: syncid=28
2003-08-27 17:03:34,927 [Thread-9] INFO replic - Rserv::replicate :
PREPARE SNAPSHOT BEGINS ...
2003-08-27 17:03:34,964 [Thread-9] INFO replic - Rserv::replicate :
PREPARED SNAPSHOT to SERVER 1 IN 42 MILLIS.; Snapshot Got Something=true
2003-08-27 17:03:34,964 [Thread-9] INFO replic - Rserv::replicate :
APPLY SNAPSHOT BEGINS ...
2003-08-27 17:03:34,978 [Thread-9] INFO replic - Rserv::syncSync: Last
SyncID applied: syncid=31
2003-08-27 17:03:34,994 [Thread-9] INFO replic - Rserv::replicate :
SUCCESSFULLY REPLICATED to SERVER 1 IN 72 MILLIS.; Average time per 1
update=?
2003-08-27 17:03:35,023 [Thread-11] INFO replic - Rserv::syncSync: Last
SyncID applied: syncid=29
2003-08-27 17:03:35,027 [Thread-11] INFO replic - Rserv::replicate :
PREPARE SNAPSHOT BEGINS ...
2003-08-27 17:03:35,075 [Thread-11] INFO replic - Rserv::replicate :
PREPARED SNAPSHOT to SERVER 2 IN 53 MILLIS.; Snapshot Got Something=true
2003-08-27 17:03:35,076 [Thread-11] INFO replic - Rserv::replicate :
APPLY SNAPSHOT BEGINS ...
2003-08-27 17:03:35,087 [Thread-11] INFO replic - Rserv::syncSync: Last
SyncID applied: syncid=32
2003-08-27 17:03:35,104 [Thread-11] INFO replic - Rserv::replicate :
SUCCESSFULLY REPLICATED to SERVER 2 IN 82 MILLIS.; Average time per 1
update=?

I tried setting it to output more debug messages by setting
'debug=true' in replication.conf, but it doesn't seem to add any more
to the logs.

The _rserv_slave_sync_ tables seem to have activity, but the
_rserv_slave_tables_ table is empty.


If my wife was standing behind me, I would expect she would say 'Its
right in front of you, dear', but I can't seem to figure out the
problem. Anyone else playing with this yet that can shed some light?


--------------------

Andrew Rawnsley
President
The Ravensfield Digital Resource Group, Ltd.
(740) 587-0114
www.ravensfield.com

Re: erserver 1.2 problem

From

Bernd Helmle

Date:

29 August 2003, 11:08:30

I've got the same issues, however, my erserver log says there's nothing to
replicate.....
I've posted to erserver-general, yesterday. If i get any hints from there,
i let you know.

--On Donnerstag, August 28, 2003 17:27:55 -0400 Andrew Rawnsley
<ronz@ravensfield.com> wrote:

>
> Downloaded the eRServer 1.2 source (thanks, guys) and installed, and am
> having a problem. Anyone else dug into this yet?
>
> Situation:
>
> PG 7.3.4 on linux (master)
> Its been tried with 3 slaves, all 7.3.4, 2 on OS X and one on Linux.
>
> It builds fine. It installs fine. I go through the setup with no problems
> (calling createlang, doing the initial ers_setup, adding tables, adding
> slaves, etc.)
>
> The startup goes fine. No complaints in the log file. It sees every slave.
>
> Problem is, nothing seems to replicate. I insert records into the tables
> on the master and nothing happens. If I am reading the logs right, it
> thinks it is:
>
> 2003-08-27 17:03:34,563 [Thread-7] INFO replic - Rserv::syncSync: Last
> SyncID applied: syncid=27 2003-08-27 17:03:34,568 [Thread-7] INFO replic
> - Rserv::replicate : PREPARE SNAPSHOT BEGINS ... 2003-08-27 17:03:34,665
> [Thread-7] INFO replic - Rserv::replicate : PREPARED SNAPSHOT to SERVER 0
> IN 102 MILLIS.; Snapshot Got Something=true 2003-08-27 17:03:34,665
> [Thread-7] INFO replic - Rserv::replicate : APPLY SNAPSHOT BEGINS ...
> 2003-08-27 17:03:34,675 [Thread-7] INFO replic - Rserv::syncSync: Last
> SyncID applied: syncid=30 2003-08-27 17:03:34,692 [Thread-7] INFO replic
> - Rserv::replicate : SUCCESSFULLY REPLICATED to SERVER 0 IN 130 MILLIS.;
> Average time per 1 update=? 2003-08-27 17:03:34,923 [Thread-9] INFO
> replic - Rserv::syncSync: Last SyncID applied: syncid=28 2003-08-27
> 17:03:34,927 [Thread-9] INFO replic - Rserv::replicate : PREPARE SNAPSHOT
> BEGINS ... 2003-08-27 17:03:34,964 [Thread-9] INFO replic -
> Rserv::replicate : PREPARED SNAPSHOT to SERVER 1 IN 42 MILLIS.; Snapshot
> Got Something=true 2003-08-27 17:03:34,964 [Thread-9] INFO replic -
> Rserv::replicate : APPLY SNAPSHOT BEGINS ... 2003-08-27 17:03:34,978
> [Thread-9] INFO replic - Rserv::syncSync: Last SyncID applied: syncid=31
> 2003-08-27 17:03:34,994 [Thread-9] INFO replic - Rserv::replicate :
> SUCCESSFULLY REPLICATED to SERVER 1 IN 72 MILLIS.; Average time per 1
> update=? 2003-08-27 17:03:35,023 [Thread-11] INFO replic -
> Rserv::syncSync: Last SyncID applied: syncid=29 2003-08-27 17:03:35,027
> [Thread-11] INFO replic - Rserv::replicate : PREPARE SNAPSHOT BEGINS ...
> 2003-08-27 17:03:35,075 [Thread-11] INFO replic - Rserv::replicate :
> PREPARED SNAPSHOT to SERVER 2 IN 53 MILLIS.; Snapshot Got Something=true
> 2003-08-27 17:03:35,076 [Thread-11] INFO replic - Rserv::replicate :
> APPLY SNAPSHOT BEGINS ... 2003-08-27 17:03:35,087 [Thread-11] INFO replic
> - Rserv::syncSync: Last SyncID applied: syncid=32 2003-08-27 17:03:35,104
> [Thread-11] INFO replic - Rserv::replicate : SUCCESSFULLY REPLICATED to
> SERVER 2 IN 82 MILLIS.; Average time per 1 update=?
>
> I tried setting it to output more debug messages by setting 'debug=true'
> in replication.conf, but it doesn't seem to add any more to the logs.
>
> The _rserv_slave_sync_ tables seem to have activity, but the
> _rserv_slave_tables_ table is empty.
>
>
> If my wife was standing behind me, I would expect she would say 'Its
> right in front of you, dear', but I can't seem to figure out the problem.
> Anyone else playing with this yet that can shed some light?
>
>
> --------------------
>
> Andrew Rawnsley
> President
> The Ravensfield Digital Resource Group, Ltd.
> (740) 587-0114
> www.ravensfield.com
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 2: you can get off all lists at once with the unregister command
>     (send "unregister YourEmailAddressHere" to majordomo@postgresql.org)
>
>



  Bernd

Re: erserver 1.2 problem

From

Andrew Rawnsley

Date:

29 August 2003, 12:13:26

It appears in my case that the ers_addtable is failing to add
everything it needs to the slave tables, with a:

DBD::Pg::st execute failed: execute on disconnected handle at
/db/erserver/lib/eRServer.pm line 54, <IN> line 22.

which is the point it actually tries to add stuff to the slave. I'm not
a perl head, so I'm not sure at the moment how to fix the problem.



On Friday, August 29, 2003, at 07:08 AM, Bernd Helmle wrote:

> I've got the same issues, however, my erserver log says there's
> nothing to replicate.....
> I've posted to erserver-general, yesterday. If i get any hints from
> there, i let you know.
>
> --On Donnerstag, August 28, 2003 17:27:55 -0400 Andrew Rawnsley
> <ronz@ravensfield.com> wrote:
>
>>
>> Downloaded the eRServer 1.2 source (thanks, guys) and installed, and
>> am
>> having a problem. Anyone else dug into this yet?
>>
>> Situation:
>>
>> PG 7.3.4 on linux (master)
>> Its been tried with 3 slaves, all 7.3.4, 2 on OS X and one on Linux.
>>
>> It builds fine. It installs fine. I go through the setup with no
>> problems
>> (calling createlang, doing the initial ers_setup, adding tables,
>> adding
>> slaves, etc.)
>>
>> The startup goes fine. No complaints in the log file. It sees every
>> slave.
>>
>> Problem is, nothing seems to replicate. I insert records into the
>> tables
>> on the master and nothing happens. If I am reading the logs right, it
>> thinks it is:
>>
>> 2003-08-27 17:03:34,563 [Thread-7] INFO replic - Rserv::syncSync: Last
>> SyncID applied: syncid=27 2003-08-27 17:03:34,568 [Thread-7] INFO
>> replic
>> - Rserv::replicate : PREPARE SNAPSHOT BEGINS ... 2003-08-27
>> 17:03:34,665
>> [Thread-7] INFO replic - Rserv::replicate : PREPARED SNAPSHOT to
>> SERVER 0
>> IN 102 MILLIS.; Snapshot Got Something=true 2003-08-27 17:03:34,665
>> [Thread-7] INFO replic - Rserv::replicate : APPLY SNAPSHOT BEGINS ...
>> 2003-08-27 17:03:34,675 [Thread-7] INFO replic - Rserv::syncSync: Last
>> SyncID applied: syncid=30 2003-08-27 17:03:34,692 [Thread-7] INFO
>> replic
>> - Rserv::replicate : SUCCESSFULLY REPLICATED to SERVER 0 IN 130
>> MILLIS.;
>> Average time per 1 update=? 2003-08-27 17:03:34,923 [Thread-9] INFO
>> replic - Rserv::syncSync: Last SyncID applied: syncid=28 2003-08-27
>> 17:03:34,927 [Thread-9] INFO replic - Rserv::replicate : PREPARE
>> SNAPSHOT
>> BEGINS ... 2003-08-27 17:03:34,964 [Thread-9] INFO replic -
>> Rserv::replicate : PREPARED SNAPSHOT to SERVER 1 IN 42 MILLIS.;
>> Snapshot
>> Got Something=true 2003-08-27 17:03:34,964 [Thread-9] INFO replic -
>> Rserv::replicate : APPLY SNAPSHOT BEGINS ... 2003-08-27 17:03:34,978
>> [Thread-9] INFO replic - Rserv::syncSync: Last SyncID applied:
>> syncid=31
>> 2003-08-27 17:03:34,994 [Thread-9] INFO replic - Rserv::replicate :
>> SUCCESSFULLY REPLICATED to SERVER 1 IN 72 MILLIS.; Average time per 1
>> update=? 2003-08-27 17:03:35,023 [Thread-11] INFO replic -
>> Rserv::syncSync: Last SyncID applied: syncid=29 2003-08-27
>> 17:03:35,027
>> [Thread-11] INFO replic - Rserv::replicate : PREPARE SNAPSHOT BEGINS
>> ...
>> 2003-08-27 17:03:35,075 [Thread-11] INFO replic - Rserv::replicate :
>> PREPARED SNAPSHOT to SERVER 2 IN 53 MILLIS.; Snapshot Got
>> Something=true
>> 2003-08-27 17:03:35,076 [Thread-11] INFO replic - Rserv::replicate :
>> APPLY SNAPSHOT BEGINS ... 2003-08-27 17:03:35,087 [Thread-11] INFO
>> replic
>> - Rserv::syncSync: Last SyncID applied: syncid=32 2003-08-27
>> 17:03:35,104
>> [Thread-11] INFO replic - Rserv::replicate : SUCCESSFULLY REPLICATED
>> to
>> SERVER 2 IN 82 MILLIS.; Average time per 1 update=?
>>
>> I tried setting it to output more debug messages by setting
>> 'debug=true'
>> in replication.conf, but it doesn't seem to add any more to the logs.
>>
>> The _rserv_slave_sync_ tables seem to have activity, but the
>> _rserv_slave_tables_ table is empty.
>>
>>
>> If my wife was standing behind me, I would expect she would say 'Its
>> right in front of you, dear', but I can't seem to figure out the
>> problem.
>> Anyone else playing with this yet that can shed some light?
>>
>>
>> --------------------
>>
>> Andrew Rawnsley
>> President
>> The Ravensfield Digital Resource Group, Ltd.
>> (740) 587-0114
>> www.ravensfield.com
>>
>>
>> ---------------------------(end of
>> broadcast)---------------------------
>> TIP 2: you can get off all lists at once with the unregister command
>>     (send "unregister YourEmailAddressHere" to
>> majordomo@postgresql.org)
>>
>>
>
>
>
>  Bernd
>
> ---------------------------(end of
> broadcast)---------------------------
> TIP 8: explain analyze is your friend
>
--------------------

Andrew Rawnsley
President
The Ravensfield Digital Resource Group, Ltd.
(740) 587-0114
www.ravensfield.com

Re: erserver 1.2 problem

From

Bernd Helmle

Date:

29 August 2003, 14:22:42

I've got the same issues, however, my erserver log says there's nothing to
replicate.....
I've posted to erserver-general, yesterday. If i get any hints from there,
i let you know.

--On Donnerstag, August 28, 2003 17:27:55 -0400 Andrew Rawnsley
<ronz@ravensfield.com> wrote:

>
> Downloaded the eRServer 1.2 source (thanks, guys) and installed, and am
> having a problem. Anyone else dug into this yet?
>
> Situation:
>
> PG 7.3.4 on linux (master)
> Its been tried with 3 slaves, all 7.3.4, 2 on OS X and one on Linux.
>
> It builds fine. It installs fine. I go through the setup with no problems
> (calling createlang, doing the initial ers_setup, adding tables, adding
> slaves, etc.)
>
> The startup goes fine. No complaints in the log file. It sees every slave.
>
> Problem is, nothing seems to replicate. I insert records into the tables
> on the master and nothing happens. If I am reading the logs right, it
> thinks it is:
>
> 2003-08-27 17:03:34,563 [Thread-7] INFO replic - Rserv::syncSync: Last
> SyncID applied: syncid=27 2003-08-27 17:03:34,568 [Thread-7] INFO replic
> - Rserv::replicate : PREPARE SNAPSHOT BEGINS ... 2003-08-27 17:03:34,665
> [Thread-7] INFO replic - Rserv::replicate : PREPARED SNAPSHOT to SERVER 0
> IN 102 MILLIS.; Snapshot Got Something=true 2003-08-27 17:03:34,665
> [Thread-7] INFO replic - Rserv::replicate : APPLY SNAPSHOT BEGINS ...
> 2003-08-27 17:03:34,675 [Thread-7] INFO replic - Rserv::syncSync: Last
> SyncID applied: syncid=30 2003-08-27 17:03:34,692 [Thread-7] INFO replic
> - Rserv::replicate : SUCCESSFULLY REPLICATED to SERVER 0 IN 130 MILLIS.;
> Average time per 1 update=? 2003-08-27 17:03:34,923 [Thread-9] INFO
> replic - Rserv::syncSync: Last SyncID applied: syncid=28 2003-08-27
> 17:03:34,927 [Thread-9] INFO replic - Rserv::replicate : PREPARE SNAPSHOT
> BEGINS ... 2003-08-27 17:03:34,964 [Thread-9] INFO replic -
> Rserv::replicate : PREPARED SNAPSHOT to SERVER 1 IN 42 MILLIS.; Snapshot
> Got Something=true 2003-08-27 17:03:34,964 [Thread-9] INFO replic -
> Rserv::replicate : APPLY SNAPSHOT BEGINS ... 2003-08-27 17:03:34,978
> [Thread-9] INFO replic - Rserv::syncSync: Last SyncID applied: syncid=31
> 2003-08-27 17:03:34,994 [Thread-9] INFO replic - Rserv::replicate :
> SUCCESSFULLY REPLICATED to SERVER 1 IN 72 MILLIS.; Average time per 1
> update=? 2003-08-27 17:03:35,023 [Thread-11] INFO replic -
> Rserv::syncSync: Last SyncID applied: syncid=29 2003-08-27 17:03:35,027
> [Thread-11] INFO replic - Rserv::replicate : PREPARE SNAPSHOT BEGINS ...
> 2003-08-27 17:03:35,075 [Thread-11] INFO replic - Rserv::replicate :
> PREPARED SNAPSHOT to SERVER 2 IN 53 MILLIS.; Snapshot Got Something=true
> 2003-08-27 17:03:35,076 [Thread-11] INFO replic - Rserv::replicate :
> APPLY SNAPSHOT BEGINS ... 2003-08-27 17:03:35,087 [Thread-11] INFO replic
> - Rserv::syncSync: Last SyncID applied: syncid=32 2003-08-27 17:03:35,104
> [Thread-11] INFO replic - Rserv::replicate : SUCCESSFULLY REPLICATED to
> SERVER 2 IN 82 MILLIS.; Average time per 1 update=?
>
> I tried setting it to output more debug messages by setting 'debug=true'
> in replication.conf, but it doesn't seem to add any more to the logs.
>
> The _rserv_slave_sync_ tables seem to have activity, but the
> _rserv_slave_tables_ table is empty.
>
>
> If my wife was standing behind me, I would expect she would say 'Its
> right in front of you, dear', but I can't seem to figure out the problem.
> Anyone else playing with this yet that can shed some light?
>
>
> --------------------
>
> Andrew Rawnsley
> President
> The Ravensfield Digital Resource Group, Ltd.
> (740) 587-0114
> www.ravensfield.com
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 2: you can get off all lists at once with the unregister command
>     (send "unregister YourEmailAddressHere" to majordomo@postgresql.org)
>
>



  Bernd

Re: erserver 1.2 problem

From

Andrew Sullivan

Date:

29 August 2003, 17:06:01

On Fri, Aug 29, 2003 at 08:13:55AM -0400, Andrew Rawnsley wrote:
>
> It appears in my case that the ers_addtable is failing to add
> everything it needs to the slave tables, with a:
>
> DBD::Pg::st execute failed: execute on disconnected handle at
> /db/erserver/lib/eRServer.pm line 54, <IN> line 22.
>
> which is the point it actually tries to add stuff to the slave. I'm not
> a perl head, so I'm not sure at the moment how to fix the problem.

Sure looks like the problem.  The versions I used (which are prior to
what was released) all used Pg.pm, and it looks like this was
re-written in DBI.

Anyway, this'll do it for you:

INSERT INTO _rserv_slave_tables_ (tname, cname, reloid, key)
    SELECT r.relname, a.attname, r.oid, a.attnum
    FROM pg_class r, pg_attribute a
    WHERE r.oid = a.attrelid
    AND r.relname = '[your_relation_name]'
    AND a.attname = '_ers_uniq'

(Uh, I _think_ it's called _ers_uniq.  Our older installation uses
the original _rserv_ts locution found in the example rserv script.
Ah, legacy.)

You can add extra slave tables this way, one at a time, if you need
to.

There's an erserver mailing list, BTW.  I'm on it.

A

--
----
Andrew Sullivan                         204-4141 Yonge Street
Liberty RMS                           Toronto, Ontario Canada
<andrew@libertyrms.info>                              M2P 2A8
                                         +1 416 646 3304 x110