pg_ready failed: connection not open

[ayokh75]

• Mojo::Pg version: 4.27
• Perl version: 5.32
• Operating system: Red Hat Enterprise Linux 8.8 (Ootpa)

Steps to reproduce the behavior

Currently no systematic way found to reproduce the observed error;

Mojo app running behind HA proxy, PG Pool and 2 Postgres servers (Primary and Secondary) (Mojo app -> HA Proxy -> Pgpool -> Postgres).
Under heavy DB async query load when DB cluster switches from primary to secondary the following logs are observed repeatedly and the Mojolicious server app becomes unresponsive to http requests:

Mojo::Reactor::EV: I/O watcher failed: DBD::Pg::db pg_ready failed: connection not open at /tmp/par-656d75/cache-5a13761dff7eacf51565680336f8b5781c26f7aa/inc/lib/Mojo/Pg/Database.pm line 173.
DBD::Pg::db pg_notifies failed: connection not open at /tmp/par-656d75/cache-5a13761dff7eacf51565680336f8b5781c26f7aa/inc/lib/Mojo/Pg/Database.pm line 142.
DBD::Pg::db pg_ready failed: connection not open at /tmp/par-656d75/cache-5a13761dff7eacf51565680336f8b5781c26f7aa/inc/lib/Mojo/Pg/Database.pm line 173.

Also the following logs are observed:
Mojo::Reactor::EV: I/O watcher failed: DBD::Pg::db pg_ready failed: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request. at /tmp/par-656d75/cache-d8b4d457ad057b3482a456dcf4386549533fd53d/inc/lib/Mojo/Pg/Database.pm line 173.

And the following too which means the Mojo app server has to be restarted to function again:
Mojo::Reactor::EV: I/O watcher failed: DBI connect('dbname=appDb;host=localhost;port=5433','dbUser',...) failed: server closed the connection unexpectedly
his probably means the server terminated abnormally
before or while processing the request. at /tmp/par-656d75/cache-5a13761dff7eacf51565680336f8b5781c26f7aa/inc/lib/Mojo/Pg.pm line 73.

Expected behavior

To be able to reconnect to the DB once Postgres server is available again without restarting the Mojo app;

Actual behavior

As explained in '### Steps to reproduce the behavior' section above;

[kraih]

This seems hard to replicate. Doubt it will be fixed quickly.

[akarelas]

I reproduced it reliably:

#!/usr/bin/env perl

use v5.42;
use FindBin '$RealBin';
use lib "$RealBin/../local/lib/perl5";

use Mojo::Base -strict, -async_await;
use Mojo::Pg;

my $pg = Mojo::Pg->new('postgresql://dbuser:dbpass@localhost/dbname');
my $db = $pg->db;

say 'foo1';
await $db->query_p('SELECT PG_SLEEP(60)');
say 'foo2';

To replicate the bug, during the 60 seconds between foo1 & foo2 restart postgresql (to close the connection).

You'll see tons of this appearing all the time, even after postgresql successfully restarts:

connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open

which are really one multi-line error message that repeats itself all the time, and gets bigger and bigger (more lines, while starting from 1-2 lines, so scroll up your terminal to see the original error that ends in "...at $module line $line")

To make your life easier, here's the error message (the first few times):

Mojo::Reactor::Poll: I/O watcher failed: DBD::Pg::db pg_ready failed: FATAL:  terminating connection due to administrator command
SSL connection has been closed unexpectedly
connection not open
connection not open at /home/appuser/work/portal/perl/temp/../local/lib/perl5/Mojo/Pg/Database.pm line 180.
Mojo::Reactor::Poll: I/O watcher failed: DBD::Pg::db pg_ready failed: FATAL:  terminating connection due to administrator command
SSL connection has been closed unexpectedly
connection not open
connection not open
connection not open
connection not open at /home/appuser/work/portal/perl/temp/../local/lib/perl5/Mojo/Pg/Database.pm line 180.
Mojo::Reactor::Poll: I/O watcher failed: DBD::Pg::db pg_ready failed: FATAL:  terminating connection due to administrator command
SSL connection has been closed unexpectedly
connection not open
connection not open
connection not open
connection not open
connection not open
connection not open at /home/appuser/work/portal/perl/temp/../local/lib/perl5/Mojo/Pg/Database.pm line 180.

See how it gets bigger every time.

This affects me a lot, because I want to use pgbouncer which (I want to) terminate the client connection when it tries to start a query when pgbouncer's whole pool is already being used, so a solution to this bug would be good for me.

(Having pgbouncer terminate the connection when pgbouncer's pool is full, is the only way I found to prevent my async perl program process from blocking forever (I don't want it to block at all) on the $dbh->ping that Mojo::Pg does when dequeuing a $dbh connection from its own pool)

[akarelas]

Ok, maybe it's a different bug, I'll open a separate issue.