Re: [HACKERS] 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-2300: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 |
logicalreplication 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-2300: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' ;

)