Re: Logical replication existing data copy

On 2017-02-22 18:13, Erik Rijkers wrote:
> On 2017-02-22 14:48, Erik Rijkers wrote:
>> On 2017-02-22 13:03, Petr Jelinek wrote:
>>
>>> 0001-Skip-unnecessary-snapshot-builds.patch
>>> 0002-Don-t-use-on-disk-snapshots-for-snapshot-export-in-l.patch
>>> 0003-Fix-xl_running_xacts-usage-in-snapshot-builder.patch
>>> 0001-Use-asynchronous-connect-API-in-libpqwalreceiver.patch
>>> 0002-Fix-after-trigger-execution-in-logical-replication.patch
>>> 0003-Add-RENAME-support-for-PUBLICATIONs-and-SUBSCRIPTION.patch
>>> 0001-Logical-replication-support-for-initial-data-copy-v5.patch
>>
>> It works well now, or at least my particular test case seems now
>> solved.
>
> Cried victory too early, I'm afraid.
>

I got into a 'hung' state while repeating pgbench_derail2.sh.

Below is some state. I notice that master pg_stat_replication.syaye is
'startup'.
Maybe I should only start the test after that state has changed. Any of
the
other possible values (catchup, streaming) wuold be OK, I would think.

$ ( dbactivity.sh ; echo "; table pg_subscription; table
pg_subscription_rel;" ) | psql -qXp 6973
now | pid | app
| state | wt_evt | wt_evt_type | query_start
| duration | query
---------------------+-------+---------------------------------------------+--------+------------------------+-------------+---------------------+----------+----------------------------------
2017-02-23 00:37:57 | 31352 | logical replication worker 47435
| active | relation | Lock |
| |
2017-02-23 00:37:57 | 397 | psql
| active | BgWorkerShutdown | IPC | 2017-02-23 00:22:14
| 00:15:42 | drop subscription if exists sub1
2017-02-23 00:37:57 | 31369 | logical replication worker 47435 sync
47423 | | LogicalSyncStateChange | IPC |
| |
2017-02-23 00:37:57 | 398 | logical replication worker 47435 sync
47418 | | transactionid | Lock |
| |
(4 rows)

subdbid | subname | subowner | subenabled | subconninfo | subslotname |
subpublications
---------+---------+----------+------------+-------------+-------------+-----------------
16384 | sub1 | 10 | t | port=6972 | sub1 |
{pub1}
(1 row)

srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+------------
47435 | 47423 | w | 2/CB078260
47435 | 47412 | r |
47435 | 47415 | r |
47435 | 47418 | c | 2/CB06E158
(4 rows)

Replica (port 6973):

[bulldog aardvark] [local]:6973 (Thu) 00:52:47 [pid:5401] [testdb] #
table pg_stat_subscription ;
subid | subname | pid | relid | received_lsn |
last_msg_send_time | last_msg_receipt_time |
latest_end_lsn | latest_end_time
-------+---------+-------+-------+--------------+-------------------------------+-------------------------------+----------------+-------------------------------
47435 | sub1 | 31369 | 47423 | | 2017-02-23
00:20:45.758072+01 | 2017-02-23 00:20:45.758072+01 | |
2017-02-23 00:20:45.758072+01
47435 | sub1 | 398 | 47418 | | 2017-02-23
00:22:14.896471+01 | 2017-02-23 00:22:14.896471+01 | |
2017-02-23 00:22:14.896471+01
47435 | sub1 | 31352 | | 2/CB06E158 |
| 2017-02-23 00:20:47.034664+01 | | 2017-02-23
00:20:45.679245+01
(3 rows)

Master (port 6972):

[bulldog aardvark] [local]:6972 (Thu) 00:48:27 [pid:5307] [testdb] # \x
on \\ table pg_stat_replication ;
Expanded display is on.
-[ RECORD 1 ]----+------------------------------
pid | 399
usesysid | 10
usename | aardvark
application_name | sub1_47435_sync_47418
client_addr |
client_hostname |
client_port | -1
backend_start | 2017-02-23 00:22:14.902701+01
backend_xmin |
state | startup
sent_location |
write_location |
flush_location |
replay_location |
sync_priority | 0
sync_state | async
-[ RECORD 2 ]----+------------------------------
pid | 31371
usesysid | 10
usename | aardvark
application_name | sub1_47435_sync_47423
client_addr |
client_hostname |
client_port | -1
backend_start | 2017-02-23 00:20:45.762852+01
backend_xmin |
state | startup
sent_location |
write_location |
flush_location |
replay_location |
sync_priority | 0
sync_state | async

( above 'dbactivity.sh' is:

select
rpad(now()::text,19) as now
, pid as pid
, application_name as app
, state as state
, wait_event as wt_evt
, wait_event_type as wt_evt_type
, date_trunc('second', query_start::timestamp) as query_start
, substring((now() - query_start)::text, 1, position('.' in (now() -
query_start)::text)-1) as duration
, query
from pg_stat_activity
where query !~ 'pg_stat_activity' ;

)