0

I am trying to establish a (logical) replica of a database on a remote site. Therefore we established a permanent VPN connection to that site where we are running two machines. One is an Ubuntu 18.10 box we use for maintenance and client operations. The other one is a Debian 9.11 which is actually running the replica Postgres 11.5 DB Host.

I wasn't able to connect the master node via the SUBSCRIPTION, therefore I tried to connect via psql from the replica node to my master node. I get asked to type in the password and then the connection timesout after about a minute.

When I try to connect from our maintenance box everything works fine. We double checked Firewall rules of the tunnel, pg_hba.coonf and deactivated all local firwalls, without success. Hosts are pingable and ports are open and listening.

I don't have any further ideas what else could cause the client to not connect to a postgres server instance.

The database is postgres 10.7, the client is 11.5.

What else could cause a client connection timeout like this?

EDIT: the exact error message on the client side is

psql: could not connect to server: Connection refused Is the server running on host "" and accepting TCP/IP connections on port 5432?

On the serverside the log contains nothing.

The server is configured to listen on '*' and accept connections as host from 0.0.0.0/0 md5 on all databases from all users. As said, the connection from another box on the remote site is working.

The working client is psql (PostgreSQL) 10.9 (Ubuntu 10.9-0ubuntu0.18.10.1)

The non-working client is psql (PostgreSQL) 11.5 (Debian 11.5-3.pgdg90+1)

EDIT2: I reconfigured log verbosity of our postgres db server to DEBUG5...this is what I get

2020-06-18 11:32:14.310 CEST [4860] DEBUG:  find_in_dynamic_libpath: trying "C:/Program Files/PostgreSQL/11/lib/pg_stat_statements"
2020-06-18 11:32:14.310 CEST [4860] DEBUG:  find_in_dynamic_libpath: trying "C:/Program Files/PostgreSQL/11/lib/pg_stat_statements.dll"
2020-06-18 11:32:14.310 CEST [4860] DEBUG:  loaded library "pg_stat_statements"
2020-06-18 11:32:14.310 CEST [4860] LOG:  connection received: host=192.168.110.124 port=47246
2020-06-18 11:32:14.321 CEST [4860] DEBUG:  postgres child[4860]: starting with (
2020-06-18 11:32:14.321 CEST [4860] DEBUG:      postgres
2020-06-18 11:32:14.321 CEST [4860] DEBUG:  )
2020-06-18 11:32:14.321 CEST [4860] DEBUG:  InitPostgres
2020-06-18 11:32:14.321 CEST [4860] DEBUG:  my backend ID is 3
2020-06-18 11:32:14.322 CEST [4860] DEBUG:  mapped win32 error code 2 to 2
2020-06-18 11:32:14.322 CEST [4860] DEBUG:  StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  shmem_exit(0): 1 before_shmem_exit callbacks to make
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  shmem_exit(0): 6 on_shmem_exit callbacks to make
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  proc_exit(0): 3 callbacks to make
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  exit(0)
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  shmem_exit(-1): 0 before_shmem_exit callbacks to make
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  shmem_exit(-1): 0 on_shmem_exit callbacks to make
2020-06-18 11:32:14.334 CEST [4860] DEBUG:  proc_exit(-1): 0 callbacks to make
2020-06-18 11:32:14.337 CEST [3892] DEBUG:  reaping dead processes
2020-06-18 11:32:14.337 CEST [3892] DEBUG:  server process (PID 4860) exited with exit code 0

A working connection from the same subnet (other machine) looks like this in the logs

2020-06-18 11:41:16.373 CEST [3892] DEBUG:  forked new backend, pid=576 socket=4932
2020-06-18 11:41:16.392 CEST [576] DEBUG:  find_in_dynamic_libpath: trying "C:/Program Files/PostgreSQL/11/lib/pg_stat_statements"
2020-06-18 11:41:16.392 CEST [576] DEBUG:  find_in_dynamic_libpath: trying "C:/Program Files/PostgreSQL/11/lib/pg_stat_statements.dll"
2020-06-18 11:41:16.392 CEST [576] DEBUG:  loaded library "pg_stat_statements"
2020-06-18 11:41:16.392 CEST [576] LOG:  connection received: host=192.168.110.111 port=44920
2020-06-18 11:41:16.403 CEST [576] DEBUG:  postgres child[576]: starting with (
2020-06-18 11:41:16.403 CEST [576] DEBUG:   postgres
2020-06-18 11:41:16.403 CEST [576] DEBUG:  )
2020-06-18 11:41:16.403 CEST [576] DEBUG:  InitPostgres
2020-06-18 11:41:16.403 CEST [576] DEBUG:  my backend ID is 5
2020-06-18 11:41:16.403 CEST [576] DEBUG:  StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2020-06-18 11:41:16.415 CEST [576] DEBUG:  received password packet
2020-06-18 11:41:16.415 CEST [576] LOG:  connection authorized: user=swwat database=swwat
2020-06-18 11:41:16.417 CEST [576] DEBUG:  CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
Improve this question
2
  • What is the precise error message, both on the client, and from the server's log file?
    – jjanes
    Jun 17, 2020 at 23:15
  • @jjanes see my EDIT
    – Jürgen Zornig
    Jun 18, 2020 at 9:04

2 Answers 2

Reset to default
2

That is a networking problem. The message and the lack of server log entries prove that you didn't reach the database server.

You'll have to use standard network debugging techniques to solve this problem.

Improve this answer
4
  • We did by using tcpdump.... both machines talk to each other... ssh, ping, telnet 5432 ...is all working, only psql runs into a timeout. I also think its a networking problem, but I don't have any further ideas where to look for
    – Jürgen Zornig
    Jun 18, 2020 at 9:16
  • See my last EDIT2 ... the backend process is crashing. No Idea why
    – Jürgen Zornig
    Jun 18, 2020 at 9:38
  • 1
    That log can never belong to that error message: the error message says you could not reach the server, the log says you did, but the client disconnected immediately after connecting. There is no crash whatsoever, the client just disconnected.
    – Laurenz Albe
    Jun 18, 2020 at 9:47
  • well...it can obviously...nevertheless you were initially right, it IS a networking problem, although a very nasty one.
    – Jürgen Zornig
    Jun 18, 2020 at 9:55
0

Finally solved it!

Our IPS (Ubiqity Firewall) identified this particular connection as a threat and disconnected it every time. Why it identified one client as a threat and not also the other one too, we don't actually know.

Accepting Laurenz Answer as his first intention was oviously right.

Improve this answer

Your Answer

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

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