erserver 1.2 problem

Started by Andrew Rawnsleyover 22 years ago5 messagesgeneral
Jump to latest
#1Andrew Rawnsley
ronz@ravensfield.com

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

#2Bernd Helmle
mailings@oopsware.de
In reply to: Andrew Rawnsley (#1)
Re: erserver 1.2 problem

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

#3Bernd Helmle
mailings@oopsware.de
In reply to: Andrew Rawnsley (#1)
Re: erserver 1.2 problem

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

#4Andrew Rawnsley
ronz@ravensfield.com
In reply to: Bernd Helmle (#3)
Re: erserver 1.2 problem

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

#5Andrew Sullivan
andrew@libertyrms.info
In reply to: Andrew Rawnsley (#4)
Re: erserver 1.2 problem

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