Re: pglogical two way replication problem

-- 
Best Regards,
Alexey Larin

Hi All,

Try to configure pglogical in such way:
srv1, srv2: CentOS 6.7, PostgreSQL 9.5.1, pglogical 1.0.1

On both servers created database "xdray", schema is common and consists tables t1 and t2.
The srv1 writes to the t1. The t1 added to replication set repset_t1 on the srv1.
The srv2 writes to the t2. The t2 added to replication set repset_t2 on the srv2.
The srv1 subscribes on repset_t2.
The srv2 subscribes on repset_t1.

      SRV1                          SRV2
+--------------+               +--------------+
|  repset_t1   |               |              |
| +---------+  |               |              |
| |t1       +--------------------->t1         |
| +---------+  |               |              |
|              |               |   repset_t2  |
|              |               |  ----------+ |
|         t2<---------------------+t2       | |
|              |               |  +---------+ |
+--------------+               +--------------+

Commands for reproduce.

On Srv1

$ psql xdray
xdray=# create table t1 (id serial constraint pk_t1 primary key);
xdray=# create table t2 (id serial constraint pk_t2 primary key);
xdray=# select pglogical.create_node('srv1','host=srv1 user=xdray dbname=xdray');
xdray=# select pglogical.create_replication_set('repset_t1');
xdray=# select pglogical.replication_set_add_table('repset_t1', 'public.t1');

On Srv2

$ psql xdray
xdray=# create table t1 (id serial constraint pk_t1 primary key);
xdray=# create table t2 (id serial constraint pk_t2 primary key);
xdray=# select pglogical.create_node('srv2','host=srv2 user=xdray dbname=xdray');
xdray=# select pglogical.create_replication_set('repset_t2');
xdray=# select pglogical.replication_set_add_table('repset_t2', 'public.t2');

On Srv1

xdray=# select pglogical.create_subscription(
  subscription_name := 'sub_t2',
  provider_dsn := 'host=srv2 user=xdray dbname=xdray',
  replication_sets := ARRAY['repset_t2'],
  synchronize_structure := false,
  synchronize_data := true);

On Svr2

xdray=# select pglogical.create_subscription(
  subscription_name := 'sub_t1',
  provider_dsn := 'host=srv1  user=xdray dbname=xdray',
  replication_sets := ARRAY['repset_t1'],
  synchronize_structure := false,
  synchronize_data := true);

So far, so good.
But as soon as we commit first transactions on any "producer" tables we have:

On Srv1
xdray=# insert into t1 default values;

On log file of Srv1 there are end less errors like:
< 2016-03-21 11:04:26.836 MSK >LOG:  worker process: pglogical apply 16385:1317353735 (PID 31952) exited with exit code 1
< 2016-03-21 11:04:26.838 MSK >LOG:  starting apply for subscription sub_t2
< 2016-03-21 11:04:26.844 MSK >ERROR:  cache lookup failed for replication origin 'pgl_xdray_srv1_sub_t1'
< 2016-03-21 11:04:26.845 MSK >LOG:  worker process: pglogical apply 16385:1317353735 (PID 31953) exited with exit code 1
< 2016-03-21 11:04:26.847 MSK >LOG:  starting apply for subscription sub_t2
< 2016-03-21 11:04:26.853 MSK >ERROR:  cache lookup failed for replication origin 'pgl_xdray_srv1_sub_t1'
< 2016-03-21 11:04:26.854 MSK >LOG:  worker process: pglogical apply 16385:1317353735 (PID 31954) exited with exit code 1
< 2016-03-21 11:04:26.856 MSK >LOG:  starting apply for subscription sub_t2
< 2016-03-21 11:04:26.862 MSK >ERROR:  cache lookup failed for replication origin 'pgl_xdray_srv1_sub_t1'

On Srv2 log:
< 2016-03-21 11:04:26.837 MSK >LOG:  could not receive data from client: Connection reset by peer
< 2016-03-21 11:04:26.837 MSK >LOG:  unexpected EOF on standby connection
< 2016-03-21 11:04:26.840 MSK >LOG:  connection received: host=192.168.0.104 port=42966
< 2016-03-21 11:04:26.842 MSK >LOG:  replication connection authorized: user=xdray
< 2016-03-21 11:04:26.844 MSK >LOG:  starting logical decoding for slot "pgl_xdray_srv2_sub_t2"
< 2016-03-21 11:04:26.844 MSK >DETAIL:  streaming transactions committing after 0/39E1060, reading WAL from 0/39E1028
< 2016-03-21 11:04:26.844 MSK >LOG:  logical decoding found consistent point at 0/39E1028
< 2016-03-21 11:04:26.844 MSK >DETAIL:  There are no running transactions.
< 2016-03-21 11:04:26.847 MSK >LOG:  could not receive data from client: Connection reset by peer
< 2016-03-21 11:04:26.847 MSK >LOG:  unexpected EOF on standby connection
< 2016-03-21 11:04:26.849 MSK >LOG:  connection received: host=192.168.0.104 port=42967
< 2016-03-21 11:04:26.851 MSK >LOG:  replication connection authorized: user=xdray
< 2016-03-21 11:04:26.853 MSK >LOG:  starting logical decoding for slot "pgl_xdray_srv2_sub_t2"
< 2016-03-21 11:04:26.853 MSK >DETAIL:  streaming transactions committing after 0/39E1060, reading WAL from 0/39E1028
< 2016-03-21 11:04:26.853 MSK >LOG:  logical decoding found consistent point at 0/39E1028
< 2016-03-21 11:04:26.853 MSK >DETAIL:  There are no running transactions.
< 2016-03-21 11:04:26.855 MSK >LOG:  could not receive data from client: Connection reset by peer
< 2016-03-21 11:04:26.855 MSK >LOG:  unexpected EOF on standby connection
< 2016-03-21 11:04:26.858 MSK >LOG:  connection received: host=192.168.0.104 port=42968
< 2016-03-21 11:04:26.860 MSK >LOG:  replication connection authorized: user=xdray
< 2016-03-21 11:04:26.862 MSK >LOG:  starting logical decoding for slot "pgl_xdray_srv2_sub_t2"
< 2016-03-21 11:04:26.862 MSK >DETAIL:  streaming transactions committing after 0/39E1060, reading WAL from 0/39E1028
< 2016-03-21 11:04:26.862 MSK >LOG:  logical decoding found consistent point at 0/39E1028
< 2016-03-21 11:04:26.862 MSK >DETAIL:  There are no running transactions.
< 2016-03-21 11:04:26.864 MSK >LOG:  could not receive data from client: Connection reset by peer
< 2016-03-21 11:04:26.864 MSK >LOG:  unexpected EOF on standby connection
< 2016-03-21 11:04:26.867 MSK >LOG:  connection received: host=192.168.0.104 port=42969
< 2016-03-21 11:04:26.869 MSK >LOG:  replication connection authorized: user=xdray
< 2016-03-21 11:04:26.871 MSK >LOG:  starting logical decoding for slot "pgl_xdray_srv2_sub_t2"
< 2016-03-21 11:04:26.871 MSK >DETAIL:  streaming transactions committing after 0/39E1060, reading WAL from 0/39E1028
< 2016-03-21 11:04:26.871 MSK >LOG:  logical decoding found consistent point at 0/39E1028
< 2016-03-21 11:04:26.871 MSK >DETAIL:  There are no running transactions.

After that replication for repset_t1 is working fine (and our insert is replicated on srv2), but repset_t2 does not work.

When we drop sub_t2 all errors are stopped.