Fetching from pgpool-II hangs indefinitely

[damjankuznar]

• asyncpg version: 0.20.1
• PostgreSQL version: 12.2
• Do you use a PostgreSQL SaaS? If so, which? Can you reproduce
  the issue with a local PostgreSQL install?: No.
• Python version: Python 3.7.7 (default, Apr 23 2020, 14:43:26)
• Platform: [GCC 8.3.0] on linux
• Do you use pgbouncer?: No, I use pgpool-II 4.1.1
• Did you install asyncpg with pip?: No, with poetry
• If you built asyncpg locally, which version of Cython did you use?: No
• Can the issue be reproduced under both asyncio and
  uvloop?: Yes

When querying the database through pgpool-II it hangs indefinitely, without raising any kind of exception. Connecting to database seems to be working, since for instance invalid password raises an exception:

asyncpg.exceptions.InternalServerError: md5 authentication failed
DETAIL:  password does not match

Steps to reproduce:

import asyncio
import asyncpg

async def run():
    conn = await asyncpg.connect(user='user', password='password',
                                 database='database', host='127.0.0.1') # connect to pgpool-II
    values = await conn.fetch('''SELECT 1''') # hangs here indefinitely
    await conn.close()

loop = asyncio.get_event_loop()
loop.run_until_complete(run())

When connecting to the PostgreSQL directly, the example above works flawlessly.

Log from pgpool-II:

May 13 20:56:00 pg01 pgpool[11982]: 2020-05-13 20:56:00: pid 13189: ERROR:  unable to read data from frontend
May 13 20:56:00 pg01 pgpool[11982]: 2020-05-13 20:56:00: pid 13189: DETAIL:  EOF encountered with frontend

[deed02392]

@damjankuznar lol, that's weird. I just came here to report this issue too after realising where the problem probably was: bitnami/charts#2568

[elprans]

Connection poolers have historically been problematic due to various liberties they take with respect to the protocol semantics, especially in the extended query flow (thus the pgbouncer quesion in the issue template).

To quickly test the hypothesis try disabling the prepared statement cache with statement_cache_size=0 in connect().

[damjankuznar]

@elprans using statement_cache_size=0 in connect doesn't change anything. It still hangs indefinitely.

[elprans]

How about await conn.execute('SELECT 1')?

[damjankuznar]

Yes, await conn.execute('SELECT 1') works!

[damjankuznar]

@elprans Will you be fixing the fetch methods or do we need to use execute?

[damjankuznar]

I've been testing a bit with execute and it also hangs indefinitely if arguments are used, e.g.:

conn.execute('''SELECT 1 WHERE 2 > $1''', 1)

Full example:

import asyncio
import asyncpg

async def run():
    conn = await asyncpg.connect(user='user', password='password',
                                 database='database', host='127.0.0.1') # connect to pgpool-II
    values = await conn.execute('''SELECT 1 WHERE 2 > $1''', 1) # hangs here indefinitely
    await conn.close()

loop = asyncio.get_event_loop()
loop.run_until_complete(run())

[elprans]

Yes, it appears the extended query protocol is completely broken with PgPool somehow.

[otsuka]

@elprans
Is there a plan to solve this problem?

Also, other than pgpool-II, if you know of a high availability and automatic failover product that can be combined with asyncpg, please let me know.
Because we can't use cloud databases like Amazon RDS, so we need to build a high availability system in an on-premises environment.

[elprans]

Also, other than pgpool-II, if you know of a high availability and automatic failover product that can be combined with asyncpg

You can use pgbouncer, just make sure you've disabled the prepared statement cache with statement_cache_size=0

[otsuka]

Hmmm... pgbouncer is not an HA product, it's just a connection pooler.

[otsuka]

The following is the log of pgpool when it runs await conn.execute('SELECT 1 WHERE 2 > $1', 1) in my environment.
Doesn't it include tips on how to solve the problem?

Yes, it appears the extended query protocol is completely broken with PgPool somehow.

Is this an issue on the pgpool side?

May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  new connection received
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: DETAIL:  connecting host=192.168.34.1 port=51064
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  md5 authentication successful with frontend
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  Parse message from frontend.
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: DETAIL:  statement: "__asyncpg_stmt_1__", query: "SELECT 1 WHERE 2 > $1"
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  DB node id: 0 backend pid: 22328 statement: SELECT version()
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  pool_reuse_block: blockid: 0
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: CONTEXT:  while searching system catalog, When relcache is missed
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  DB node id: 0 backend pid: 22328 statement: Parse: SELECT 1 WHERE 2 > $1
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  Describe message from frontend.
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: DETAIL:  statement: "__asyncpg_stmt_1__"
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  DB node id: 0 backend pid: 22328 statement: D message
May 17 14:26:16  pgpool[22264]: 2020-05-17 14:26:16: pid 22286: LOG:  Flush message from frontend.

(Hangs here)

May 17 14:26:59  pgpool[22264]: 2020-05-17 14:26:59: pid 22286: LOG:  Sync message from frontend.
May 17 14:26:59  pgpool[22264]: 2020-05-17 14:26:59: pid 22286: ERROR:  unable to read data from frontend
May 17 14:26:59  pgpool[22264]: 2020-05-17 14:26:59: pid 22286: DETAIL:  socket read failed with an error "Connection reset by peer"
May 17 14:26:59  pgpool[22264]: 2020-05-17 14:26:59: pid 22277: LOG:  new connection received
May 17 14:26:59  pgpool[22264]: 2020-05-17 14:26:59: pid 22277: DETAIL:  connecting host=192.168.34.1 port=51068

[lff0305]

Got the exactly same issue for asyncpg / pgpool II. (Tested different PG versions behind pg pool II, including 11.x, 12.x)

But asyncpg is good for stolon project (https://github.com/sorintlab/stolon)

[v-y-a-s]

I can confirm the same - Using K8S with PG Pool and bitanmi charts.

[cro]

So it sounds like this is something that needs to be fixed on the pgpool side? There are no workarounds for asyncpg?