Re: Logical Replication WIP

On 2016-12-18 11:12, Petr Jelinek wrote:

(now using latest: patchset:)

0001-Add-PUBLICATION-catalogs-and-DDL-v14.patch
0002-Add-SUBSCRIPTION-catalog-and-DDL-v14.patch
0003-Define-logical-replication-protocol-and-output-plugi-v14.patch
0004-Add-logical-replication-workers-v14.patch
0005-Add-separate-synchronous-commit-control-for-logical--v14.patch

> BTW you don't need to add primary key to pgbench_history. Simply ALTER
> TABLE pgbench_history REPLICA IDENTITY FULL; should be enough.

Either should, but neither is.

set-up:
Before creating the publication/subscription:
On master I run pgbench -qis 1, then set replica identity (and/or add
serial column) for pgbench_history, then dump/restore the 4 pgbench
tables from master to replica.
Then enabling publication/subscription. logs looks well. (Other tests
I've devised earlier (on other tables) still work nicely.)

Now when I do a pgbench-run on master, something like:

pgbench -c 1 -T 20 -P 1

I often see this (when running pgbench):

ERROR: publisher does not send replica identity column expected by the
logical replication target public.pgbench_tellers
or, sometimes (less often) the same ERROR for pgbench_accounts appears
(as in the subsciber-log below)

-- publisher log
2016-12-19 07:44:22.738 CET 22690 LOG: logical decoding found
consistent point at 0/14598C78
2016-12-19 07:44:22.738 CET 22690 DETAIL: There are no running
transactions.
2016-12-19 07:44:22.738 CET 22690 LOG: exported logical decoding
snapshot: "000130FA-1" with 0 transaction IDs
2016-12-19 07:44:22.886 CET 22729 LOG: starting logical decoding for
slot "sub1"
2016-12-19 07:44:22.886 CET 22729 DETAIL: streaming transactions
committing after 0/14598CB0, reading WAL from 0/14598C78
2016-12-19 07:44:22.886 CET 22729 LOG: logical decoding found
consistent point at 0/14598C78
2016-12-19 07:44:22.886 CET 22729 DETAIL: There are no running
transactions.
2016-12-19 07:45:25.568 CET 22729 LOG: could not receive data from
client: Connection reset by peer
2016-12-19 07:45:25.568 CET 22729 LOG: unexpected EOF on standby
connection
2016-12-19 07:45:25.580 CET 26696 LOG: starting logical decoding for
slot "sub1"
2016-12-19 07:45:25.580 CET 26696 DETAIL: streaming transactions
committing after 0/1468E0D0, reading WAL from 0/1468DC90
2016-12-19 07:45:25.589 CET 26696 LOG: logical decoding found
consistent point at 0/1468DC90
2016-12-19 07:45:25.589 CET 26696 DETAIL: There are no running
transactions.

-- subscriber log
2016-12-19 07:44:22.878 CET 17027 LOG: starting logical replication
worker for subscription 24581
2016-12-19 07:44:22.883 CET 22726 LOG: logical replication apply for
subscription sub1 started
2016-12-19 07:45:11.069 CET 22726 WARNING: leaked hash_seq_search scan
for hash table 0x2def1a8
2016-12-19 07:45:25.566 CET 22726 ERROR: publisher does not send
replica identity column expected by the logical replication target
public.pgbench_accounts
2016-12-19 07:45:25.568 CET 16984 LOG: worker process: logical
replication worker 24581 (PID 22726) exited with exit code 1
2016-12-19 07:45:25.568 CET 17027 LOG: starting logical replication
worker for subscription 24581
2016-12-19 07:45:25.574 CET 26695 LOG: logical replication apply for
subscription sub1 started
2016-12-19 07:46:10.950 CET 26695 WARNING: leaked hash_seq_search scan
for hash table 0x2def2c8
2016-12-19 07:46:10.950 CET 26695 WARNING: leaked hash_seq_search scan
for hash table 0x2def2c8
2016-12-19 07:46:10.950 CET 26695 WARNING: leaked hash_seq_search scan
for hash table 0x2def2c8

Sometimes replication (caused by a pgbench run) runs for a few seconds
replicating all 4 pgbench tables correctly, but never longer than 10 to
20 seconds.

If you cannot reproduce with the provided info it I will make a more
precise setup-desciption, but it's so solidly failing here that I hope
that won't be necessary.

Erik Rijkers