[pgpool-general: 8846] Re: Connection Lost while application is connecting to Database through PgPool

[Bo Peng]

Hi,

If the connection between Pgpool and PostgreSQL was unexpectedly closed
or the backend process was terminated abnormally,
the error "ERROR:  unable to read data from DB node" occurs.

According to the details of the messages "Connection reset by peer" and "Broken Pipe",
I think they may be caused by network problems or settings.

If it is possible, could you check if these error occur
when your application connects to PostgreSQL directly.

Best regards,

On Mon, 19 Jun 2023 12:18:08 +0530
Aviral Singh <aviral.singh21 at gmail.com> wrote:

> Hello,
> 
> Let's say, a Java application is trying to read data from Database and for
> that it establishes a connection through PgPool-II. Not all but a few
> queries are throwing warning/error like "Connection reset by peer" or
> "Broken Pipe" or "Unable to flush data to backend" in pgpool.
> 
> OS Version: Ubuntu 22.04.1 LTS
> PostgreSQL Version: 13.8
> PgPool Version: 4.2.5
> Cluster-Management of Database: Patroni-ETCD(1 Leader + 2 Replica Nodes)
> 
> I am mentioning logs for your reference for all three services, *modules*(which
> are connecting to the database)/*pgpool*/*database* which are extracted at
> the same time.
> 
> *Application Logs:*
> 2023-06-15 09:56:41.014 [app-name] [app-name] [WARN ] [scheduler-3]
> [PoolBase.java]isConnectionAlive(184) : timescaledb - Failed to validate
> connection org.postgresql.jdbc.PgConnection at 623dcf4c (This connection has
> been closed.). Possibly consider using a shorter maxLifetime value.
> 2023-06-15 09:56:41.017 [app-name] [app-name] [WARN ] [scheduler-3]
> [PoolBase.java]isConnectionAlive(184) : timescaledb - Failed to validate
> connection org.postgresql.jdbc.PgConnection at 359610bd (This connection has
> been closed.). Possibly consider using a shorter maxLifetime value.
> 2023-06-15 09:56:41.019 [app-name] [app-name] [WARN ] [scheduler-3]
> [PoolBase.java]isConnectionAlive(184) : timescaledb - Failed to validate
> connection org.postgresql.jdbc.PgConnection at 7ba2704e (This connection has
> been closed.). Possibly consider using a shorter maxLifetime value.
> 2023-06-15 09:56:41.020 [app-name] [app-name] [WARN ] [scheduler-3]
> [PoolBase.java]isConnectionAlive(184) : timescaledb - Failed to validate
> connection org.postgresql.jdbc.PgConnection at 77e997d9 (This connection has
> been closed.). Possibly consider using a shorter maxLifetime value.
> 2023-06-15 09:56:41.021 [app-name] [app-name] [WARN ] [scheduler-3]
> [PoolBase.java]isConnectionAlive(184) : timescaledb - Failed to validate
> connection org.postgresql.jdbc.PgConnection at 6dddd55d (This connection has
> been closed.). Possibly consider using a shorter maxLifetime value.
> 2023-06-15 09:56:41.023 [app-name] [app-name] [WARN ] [scheduler-3]
> [PoolBase.java]isConnectionAlive(184) : timescaledb - Failed to validate
> connection org.postgresql.jdbc.PgConnection at 684b33a3 (This connection has
> been closed.). Possibly consider using a shorter maxLifetime value.
> 
> *PgPool Logs:*
> 2023-06-15 09:56:41: pid 32465: WARNING:  write on backend 1 failed with
> error :"Connection reset by peer"
> 2023-06-15 09:56:41: pid 32465: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 32465: ERROR:  unable to flush data to backend
> 2023-06-15 09:56:41: pid 32465: DETAIL:  do not failover because
> failover_on_backend_error is off
> 2023-06-15 09:56:41: pid 32465: WARNING:  write on backend 1 failed with
> error :"Broken pipe"
> 2023-06-15 09:56:41: pid 32465: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 34920: ERROR:  unable to read data from DB node 2
> 2023-06-15 09:56:41: pid 34920: DETAIL:  socket read failed with error
> "Connection reset by peer"
> 2023-06-15 09:56:41: pid 34920: WARNING:  write on backend 2 failed with
> error :"Broken pipe"
> 2023-06-15 09:56:41: pid 34920: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 34494: ERROR:  unable to read data from DB node 0
> 2023-06-15 09:56:41: pid 34494: DETAIL:  socket read failed with error
> "Connection reset by peer"
> 2023-06-15 09:56:41: pid 34494: WARNING:  write on backend 0 failed with
> error :"Broken pipe"
> 2023-06-15 09:56:41: pid 34494: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 34494: WARNING:  write on backend 2 failed with
> error :"Connection reset by peer"
> 2023-06-15 09:56:41: pid 34494: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 32948: ERROR:  unable to read data from DB node 0
> 2023-06-15 09:56:41: pid 32948: DETAIL:  socket read failed with error
> "Connection reset by peer"
> 2023-06-15 09:56:41: pid 32948: WARNING:  write on backend 0 failed with
> error :"Broken pipe"
> 2023-06-15 09:56:41: pid 32948: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 32948: WARNING:  write on backend 2 failed with
> error :"Connection reset by peer"
> 2023-06-15 09:56:41: pid 32948: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 34985: ERROR:  unable to read data from DB node 0
> 2023-06-15 09:56:41: pid 34985: DETAIL:  socket read failed with error
> "Connection reset by peer"
> 2023-06-15 09:56:41: pid 34985: WARNING:  write on backend 0 failed with
> error :"Broken pipe"
> 2023-06-15 09:56:41: pid 34985: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 2023-06-15 09:56:41: pid 34875: ERROR:  unable to read data from DB node 2
> 2023-06-15 09:56:41: pid 34875: DETAIL:  socket read failed with error
> "Connection reset by peer"
> 2023-06-15 09:56:41: pid 34875: WARNING:  write on backend 2 failed with
> error :"Broken pipe"
> 2023-06-15 09:56:41: pid 34875: DETAIL:  while trying to write data from
> offset: 0 wlen: 5
> 
> *PostgreSQL Logs:*
> 2023-06-15 09:27:57  [PID-1]: [SessionID_1-1]
> [unknown]@[unknown],app=[unknown] [00000] LOG:  connection received:
> host=[ip-address] port=[port_no]
> 2023-06-15 09:27:57  [PID-1]: [SessionID_1-2] db-name at user-name,app=[unknown]
> [00000] LOG:  connection authorized: user=user-name database=db-name
> 2023-06-15 09:56:41  [PID-1]: [SessionID_1-3] db-name at user-name,app=PostgreSQL
> JDBC Driver [08006] LOG:  could not send data to client: Connection reset
> by peer
> 2023-06-15 09:56:41  [PID-1]: [SessionID_1-4] db-name at user-name,app=PostgreSQL
> JDBC Driver [08006] FATAL:  connection to client lost
> 2023-06-15 09:56:41  [PID-1]: [SessionID_1-5] db-name at user-name,app=PostgreSQL
> JDBC Driver [00000] LOG:  disconnection: session time: 0:28:43.104
> user=user-name database=db-name host=[ip-address] port=[port_no]
> 
> 
> Seeing the Application Logs, I assumed that reducing the value of
> maxLifetime in Hikari Pool will fix everything. But I tried to *read data
> through DBeaver also*, but still got the same issue. So I guess this issue
> is related to the Pgpool-II or PostgreSQL side.
> 
> Along with not being able to identify why this is happening, I am also
> unable to identify in pgpool logs why it is reading from replica nodes as I
> have disabled the Load Balancing in PgPool configuration.
> 
> Can you please help me with this? Is it an issue or is it a bug? If you can
> help me with this then that will be very helpful. If not then can you
> please suggest to me any forum where I can discuss the solution.
> -- 
> *Thanks & Regards*
> Aviral Singh
> Contact No: 8765789951


-- 
Bo Peng <pengbo at sraoss.co.jp>
SRA OSS LLC
TEL: 03-5979-2701 FAX: 03-5979-2702
URL: https://www.sraoss.co.jp/