8

On my local machine, I just upgraded to the latest postgres.app to get version 10. Before doing this, I ran pg_dumpall on the 9.6 database and then after installing version 10, I executed the script to re-create the databases, users, etc... I also changed the wal_level to logical after running the script from dumpall and updated some logging settings.

I first created a subscription in the dot database (as superuser)

bill=# \connect dot;
You are now connected to database "dot" as user "bill".
dot=# create publication foo for table dot.item;
CREATE PUBLICATION

There are about 39k rows in the item table, so it shouldn't take that long to sync the data.

Next, I create a new database called dot2 owned by the same user as the dot database, and I created an empty item table in the same schema as it exists in the dot database, and then I tried to subscribe to the the publication in the other database (also as superuser).

bill=# \connect dot2;
You are now connected to database "dot2" as user "bill".
dot2=# create subscription bar connection 'host=localhost port=5432 dbname=dot connect_timeout=10' PUBLICATION foo;

However, this just hangs. It does not return.

In my log, all I see is this...

2017-11-26 21:36:52.828 EST bill@dot2 54567 [local] STATEMENT:  create subscription bar connection 'host=localhost port=5432 dbname=dot connect_timeout=10' PUBLICATION foo;
2017-11-26 21:36:55.122 EST bill@dot 54978 ::1(61990) LOG:  duration: 9.328 ms  statement: SELECT DISTINCT t.schemaname, t.tablename
  FROM pg_catalog.pg_publication_tables t
 WHERE t.pubname IN ('foo')
2017-11-26 21:36:55.126 EST bill@dot 54978 ::1(61990) LOG:  logical decoding found initial starting point at 0/4584A5A8
2017-11-26 21:36:55.126 EST bill@dot 54978 ::1(61990) DETAIL:  Waiting for transactions (approximately 1) older than 1613 to end.

Attempting to look in pg_stat_activity (disclaimer -- I don't know what I'm doing here) and I see this in the publish database...

edit Adding more details from pg_state. null values elided for (some) brevity.

dot=# select * from pg_stat_activity;
-[ RECORD 1 ]----+-------------------------------------------------------------------------------------------------------------
pid              | 54323
backend_start    | 2017-11-26 21:04:40.467211-05
wait_event_type  | Activity
wait_event       | AutoVacuumMain
backend_type     | autovacuum launcher
-[ RECORD 2 ]----+-------------------------------------------------------------------------------------------------------------
pid              | 54325
usesysid         | 10
usename          | postgres
backend_start    | 2017-11-26 21:04:40.467857-05
wait_event_type  | Activity
wait_event       | LogicalLauncherMain
backend_type     | background worker
-[ RECORD 3 ]----+-------------------------------------------------------------------------------------------------------------
datid            | 16391
datname          | dot
pid              | 54978
usesysid         | 16384
usename          | bill
application_name | bar
client_addr      | ::1
client_port      | 61990
backend_start    | 2017-11-26 21:36:55.110362-05
xact_start       | 
query_start      | 2017-11-26 21:36:55.113552-05
state_change     | 2017-11-26 21:36:55.122976-05
wait_event_type  | Lock
wait_event       | transactionid
state            | idle
query            | SELECT DISTINCT t.schemaname, t.tablename                                                                   +
                 |   FROM pg_catalog.pg_publication_tables t                                                                   +
                 |  WHERE t.pubname IN ('foo')
backend_type     | walsender
-[ RECORD 4 ]----+-------------------------------------------------------------------------------------------------------------
datid            | 16391
datname          | dot
pid              | 54533
usesysid         | 16384
usename          | bill
application_name | psql
client_port      | -1
backend_start    | 2017-11-26 21:07:00.309111-05
xact_start       | 2017-11-26 22:16:11.140318-05
query_start      | 2017-11-26 22:16:11.140318-05
state_change     | 2017-11-26 22:16:11.140321-05
state            | active
backend_xmin     | 1612
query            | select * from pg_stat_activity;
backend_type     | client backend
-[ RECORD 5 ]----+-------------------------------------------------------------------------------------------------------------
datid            | 18611
datname          | dot2
pid              | 54567
usesysid         | 16384
usename          | bill
application_name | psql
client_port      | -1
backend_start    | 2017-11-26 21:09:12.969232-05
xact_start       | 2017-11-26 21:36:55.106831-05
query_start      | 2017-11-26 21:36:55.106831-05
state_change     | 2017-11-26 21:36:55.106835-05
wait_event_type  | Client
wait_event       | LibPQWalReceiverReceive
state            | active
backend_xid      | 1612
backend_xmin     | 1612
query            | create subscription bar connection 'host=localhost port=5432 dbname=dot connect_timeout=10' PUBLICATION foo;
backend_type     | client backend
-[ RECORD 6 ]----+-------------------------------------------------------------------------------------------------------------
pid              | 54321
backend_start    | 2017-11-26 21:04:40.466525-05
wait_event_type  | Activity
wait_event       | BgWriterMain
backend_type     | background writer
-[ RECORD 7 ]----+-------------------------------------------------------------------------------------------------------------
pid              | 54320
backend_start    | 2017-11-26 21:04:40.466302-05
wait_event_type  | Activity
wait_event       | CheckpointerMain
backend_type     | checkpointer
-[ RECORD 8 ]----+-------------------------------------------------------------------------------------------------------------
pid              | 54322
backend_start    | 2017-11-26 21:04:40.466712-05
wait_event_type  | Activity
wait_event       | WalWriterMain
backend_type     | walwriter

Adding pg_locks on request. Again, null values are elided.

dot=# select * from pg_locks;
-[ RECORD 1 ]------+-----------------
locktype           | relation
database           | 18611
relation           | 6102
virtualtransaction | 5/16
pid                | 54567
mode               | RowExclusiveLock
granted            | t
fastpath           | t
-[ RECORD 2 ]------+-----------------
locktype           | relation
database           | 18611
relation           | 18635
virtualtransaction | 5/16
pid                | 54567
mode               | AccessShareLock
granted            | t
fastpath           | t
-[ RECORD 3 ]------+-----------------
locktype           | virtualxid
virtualxid         | 5/16
virtualtransaction | 5/16
pid                | 54567
mode               | ExclusiveLock
granted            | t
fastpath           | t
-[ RECORD 4 ]------+-----------------
locktype           | relation
database           | 16391
relation           | 11577
virtualtransaction | 4/21
pid                | 54533
mode               | AccessShareLock
granted            | t
fastpath           | t
-[ RECORD 5 ]------+-----------------
locktype           | virtualxid
virtualxid         | 4/21
virtualtransaction | 4/21
pid                | 54533
mode               | ExclusiveLock
granted            | t
fastpath           | t
-[ RECORD 6 ]------+-----------------
locktype           | transactionid
transactionid      | 1612
virtualtransaction | 5/16
pid                | 54567
mode               | ExclusiveLock
granted            | t
fastpath           | f
-[ RECORD 7 ]------+-----------------
locktype           | object
database           | 0
classid            | 6100
objid              | 18661
objsubid           | 0
virtualtransaction | 5/16
pid                | 54567
mode               | AccessShareLock
granted            | t
fastpath           | f
-[ RECORD 8 ]------+-----------------
locktype           | transactionid
transactionid      | 1612
virtualtransaction | 3/0
pid                | 54978
mode               | ShareLock
granted            | f
fastpath           | f
-[ RECORD 9 ]------+-----------------
locktype           | relation
database           | 0
relation           | 6100
virtualtransaction | 5/16
pid                | 54567
mode               | RowExclusiveLock
granted            | t
fastpath           | f
-[ RECORD 10 ]-----+-----------------
locktype           | object
database           | 0
classid            | 1260
objid              | 16384
objsubid           | 0
virtualtransaction | 5/16
pid                | 54567
mode               | AccessShareLock
granted            | t
fastpath           | f

I've tried restarting the database, and I've shut down any processes that might connect to it. The only thing that I'm using that would connect to it are the two psql instances that I'm using to connect to both pub and sub databases.

Any idea why this occurs or what I should look at to figure out why it's waiting?

Improve this question
5
  • We would need the rest of pg_stat_activity, and at the very least the state for that specific row. You have 7 other rows you're withholding.
    – Evan Carroll
    Commented Nov 27, 2017 at 3:15
  • @EvanCarroll I was afraid that would be too much, but yeah makes sense. I added all non-null values from pg_stat_activity. Thanks
    – BillRobertson42
    Commented Nov 27, 2017 at 3:24
  • what version exactly of PostgreSQL are you using? 10? 10.1?
    – Evan Carroll
    Commented Nov 27, 2017 at 3:26
  • paste the result of select * from pg_locks
    – Evan Carroll
    Commented Nov 27, 2017 at 3:29
  • @EvanCarroll I have added pg_locks. It is version 10.1.
    – BillRobertson42
    Commented Nov 27, 2017 at 3:37

1 Answer 1

Reset to default
10

From the docs:

Creating a subscription that connects to the same database cluster (for example, to replicate between databases in the same cluster or to replicate within the same database) will only succeed if the replication slot is not created as part of the same command. Otherwise, the CREATE SUBSCRIPTION call will hang. To make this work, create the replication slot separately (using the function pg_create_logical_replication_slot with the plugin name pgoutput) and create the subscription using the parameter create_slot = false. This is an implementation restriction that might be lifted in a future release.

Improve this answer
5
  • In this context does "database cluster" mean database server process? BTW, when I read this initially, I understood it to mean that it would hang within the same database instance.
    – BillRobertson42
    Commented Nov 27, 2017 at 18:10
  • Unfortunately, I don't know what you mean by either "database server process" or "database instance". A cluster is the postmaster and all the things running under it, listening on a single port and running in a single data directory. Since you are using \connect to switch between databases without specifying a port, that means they are on the same cluster, as otherwise you couldn't do that. It is unfortunate they chose the word "cluster" for this, as it has grown new meanings in the last 30 years which makes it confusing now.
    – jjanes
    Commented Nov 27, 2017 at 21:16
  • That answers my question. Thanks. Was trying to distinguish the "database server" from the "database instances" contained within and served up by the server not sure if that clears up what I was trying to say (if that even helps). I also agree with you in that the word cluster overloaded. It threw me off.
    – BillRobertson42
    Commented Nov 28, 2017 at 4:42
  • I do that but nothing happens, the replication does not work. =( What i am missing, slot_name= i specified the name of the slot i created. I am typing l+ and not see the database growing. I have a lot of tables published in that.
    – Luciano Andress Martini
    Commented Oct 10, 2018 at 14:42
  • @LucianoAndressMartini Look in the server log file to see what errors it is showing. You should probably create your own post showing the full details of what you did.
    – jjanes
    Commented Oct 13, 2018 at 14:12

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.