Re: Logical Replication WIP

On 2016-08-31 22:51, Petr Jelinek wrote:
>
> and one more version with bug fixes, improved code docs and couple

I am not able to get the replication to work. Would you (or anyone) be
so kind to point out what I am doing wrong?

Patches applied, compiled, make-checked, installed OK.

I have 2 copies compiled and installed, logical_replication and
logical_replication2, to be publisher and subscriber, ports 6972 and
6973 respectively.

( BTW, there is no postgres user; OS user is 'aardvark'. 'aardvark is
also db superuser, and
it is also the user as which the two installations are installed. )

PGPASSFILE is set up and works for both instances.

both pg_hba.conf's changed to have:
local replication aardvark md5

instances.sh
--------------------------------------------------------------------
#!/bin/sh
project1=logical_replication # publisher
project2=logical_replication2 # subscriber
pg_stuff_dir=$HOME/pg_stuff
PATH1=$pg_stuff_dir/pg_installations/pgsql.$project1/bin:$PATH
PATH2=$pg_stuff_dir/pg_installations/pgsql.$project2/bin:$PATH
server_dir1=$pg_stuff_dir/pg_installations/pgsql.$project1
server_dir2=$pg_stuff_dir/pg_installations/pgsql.$project2
port1=6972
port2=6973
data_dir1=$server_dir1/data
data_dir2=$server_dir2/data
options1="
-c wal_level=logical
-c max_replication_slots=10
-c max_worker_processes=12
-c max_logical_replication_workers=10
-c max_wal_senders=10
-c logging_collector=on
-c log_directory=$server_dir1
-c log_filename=logfile.${project1} "

options2="
-c wal_level=logical
-c max_replication_slots=10
-c max_worker_processes=12
-c max_logical_replication_workers=10
-c max_wal_senders=10
-c logging_collector=on
-c log_directory=$server_dir2
-c log_filename=logfile.${project2} "

# start two instances:
export PATH=$PATH1; postgres -D $data_dir1 -p $port1 ${options1} &

export PATH=$PATH2; postgres -D $data_dir2 -p $port2 ${options2} &
--------------------------------------------------------------------

Both instances run fine.

On publisher db:
Create a table testt, with 20 rows.

CREATE PUBLICATION pub1 FOR TABLE testt ;
No problem.

On Subscriber db:
CREATE SUBSCRIPTION sub1 WITH CONNECTION 'host=/tmp dbname=testdb
port=6972' PUBLICATION pub1 INITIALLY DISABLED;
ALTER SUBSCRIPTION sub1 enable;

Adding rows to the table (publisher-side) gets activity going. I give
the resulting logs of both sides:

Logfile publisher side:
[...]
2016-09-07 13:47:44.287 CEST 21995 LOG: logical replication launcher
started
2016-09-07 13:51:42.601 CEST 22141 LOG: logical decoding found
consistent point at 0/230F478
2016-09-07 13:51:42.601 CEST 22141 DETAIL: There are no running
transactions.
2016-09-07 13:51:42.601 CEST 22141 LOG: exported logical decoding
snapshot: "00000702-1" with 0 transaction IDs
2016-09-07 13:52:11.326 CEST 22144 LOG: starting logical decoding for
slot "sub1"
2016-09-07 13:52:11.326 CEST 22144 DETAIL: streaming transactions
committing after 0/230F4B0, reading WAL from 0/230F478
2016-09-07 13:52:11.326 CEST 22144 LOG: logical decoding found
consistent point at 0/230F478
2016-09-07 13:52:11.326 CEST 22144 DETAIL: There are no running
transactions.
2016-09-07 13:53:47.012 CEST 22144 LOG: could not receive data from
client: Connection reset by peer
2016-09-07 13:53:47.012 CEST 22144 LOG: unexpected EOF on standby
connection
2016-09-07 13:53:47.025 CEST 22185 LOG: starting logical decoding for
slot "sub1"
2016-09-07 13:53:47.025 CEST 22185 DETAIL: streaming transactions
committing after 0/230F628, reading WAL from 0/230F5F0
2016-09-07 13:53:47.025 CEST 22185 LOG: logical decoding found
consistent point at 0/230F5F0
2016-09-07 13:53:47.025 CEST 22185 DETAIL: There are no running
transactions.
2016-09-07 13:53:47.030 CEST 22185 LOG: could not receive data from
client: Connection reset by peer
2016-09-07 13:53:47.030 CEST 22185 LOG: unexpected EOF on standby
connection
2016-09-07 13:53:52.044 CEST 22188 LOG: starting logical decoding for
slot "sub1"
2016-09-07 13:53:52.044 CEST 22188 DETAIL: streaming transactions
committing after 0/230F628, reading WAL from 0/230F5F0
2016-09-07 13:53:52.044 CEST 22188 LOG: logical decoding found
consistent point at 0/230F5F0
2016-09-07 13:53:52.044 CEST 22188 DETAIL: There are no running
transactions.
2016-09-07 13:53:52.195 CEST 22188 LOG: could not receive data from
client: Connection reset by peer
2016-09-07 13:53:52.195 CEST 22188 LOG: unexpected EOF on standby
connection
(repeat every few seconds)

Logfile subscriber-side:
[...]
2016-09-07 13:47:44.441 CEST 21997 LOG: MultiXact member wraparound
protections are now enabled
2016-09-07 13:47:44.528 CEST 21986 LOG: database system is ready to
accept connections
2016-09-07 13:47:44.529 CEST 22002 LOG: logical replication launcher
started
2016-09-07 13:52:11.319 CEST 22143 LOG: logical replication apply for
subscription sub1 started
2016-09-07 13:53:47.010 CEST 22143 ERROR: could not open relation with
OID 0
2016-09-07 13:53:47.012 CEST 21986 LOG: worker process: logical
replication worker 24048 (PID 22143) exited with exit code 1
2016-09-07 13:53:47.018 CEST 22184 LOG: logical replication apply for
subscription sub1 started
2016-09-07 13:53:47.028 CEST 22184 ERROR: could not open relation with
OID 0
2016-09-07 13:53:47.030 CEST 21986 LOG: worker process: logical
replication worker 24048 (PID 22184) exited with exit code 1
2016-09-07 13:53:52.041 CEST 22187 LOG: logical replication apply for
subscription sub1 started
2016-09-07 13:53:52.045 CEST 22187 ERROR: could not open relation with
OID 0
2016-09-07 13:53:52.046 CEST 21986 LOG: worker process: logical
replication worker 24048 (PID 22187) exited with exit code 1
(repeat every few seconds)

Any hints welcome.

Thanks!

Erik Rijkers