Delay on first access to enum columns using prepared statements

[mivds]

• asyncpg version: 0.22.0
• PostgreSQL version: 12.6, 13.2
• Do you use a PostgreSQL SaaS? If so, which? Can you reproduce
  the issue with a local PostgreSQL install?: No SaaS, reproducible using local PostgreSQL.
• Python version: 3.7, 3.8, 3.9
• Platform: Debian/Ubuntu (both show the issue)
• Do you use pgbouncer?: No
• Did you install asyncpg with pip?: Yes
• If you built asyncpg locally, which version of Cython did you use?: N/A
• Can the issue be reproduced under both asyncio and uvloop?: Yes

I am observing a delay when accessing a table with enum columns using prepared statements. My code uses SQLAlchemy's ORM in combination with asyncpg, but I've received help in narrowing it down to an issue with asyncpg's prepared statements (see the SQLAlchemy mailing list for more info).

Example application to reproduce the issue:

import asyncio
import asyncpg
import enum
from sqlalchemy import Enum, Column, Integer
from sqlalchemy.ext.asyncio import create_async_engine
from sqlalchemy.ext.declarative import declarative_base


Base = declarative_base()


class A(enum.Enum):
    ONE = 1
    TWO = 2


class B(enum.Enum):
    THREE = 3
    FOUR = 4


class C(enum.Enum):
    FIVE = 5
    SIX = 6


class RecordA(Base):
    __tablename__ = "TableA"

    id = Column(Integer, primary_key=True, autoincrement=True)
    a = Column(Enum(A))


class RecordB(Base):
    __tablename__ = "TableB"

    id = Column(Integer, primary_key=True, autoincrement=True)
    b = Column(Enum(B))
    c = Column(Enum(C))


async def main(db_url):
    from datetime import datetime

    engine = create_async_engine(db_url, echo="debug")

    async with engine.begin() as conn:
        await conn.run_sync(Base.metadata.drop_all)
        await conn.run_sync(Base.metadata.create_all)

    conn = await asyncpg.connect(db_url.replace('postgresql+asyncpg', 'postgresql'))
    async with conn.transaction():
        print(datetime.now().isoformat(), 's1 prepare')
        prep = await conn.prepare('INSERT INTO "TableA" (a) VALUES ($1) RETURNING "TableA".id')
        print(datetime.now().isoformat(), 's1 fetch')
        await prep.fetch(A.ONE.name)
    async with conn.transaction():
        print(datetime.now().isoformat(), 's2 prepare')
        prep = await conn.prepare('INSERT INTO "TableB" (b, c) VALUES ($1, $2) RETURNING "TableB".id')
        print(datetime.now().isoformat(), 's2 fetch')
        await prep.fetch(B.THREE.name, C.FIVE.name)
    async with conn.transaction():
        print(datetime.now().isoformat(), 's3 prepare')
        prep = await conn.prepare('INSERT INTO "TableB" (b, c) VALUES ($1, $2) RETURNING "TableB".id')
        print(datetime.now().isoformat(), 's3 fetch')
        await prep.fetch(B.FOUR.name, C.SIX.name)
    await conn.close()

asyncio.run(main("postgresql+asyncpg://postgres:[email protected]"))

Logging output of the 3 insert operations shows:

2021-03-27T09:33:22.233757 s1 prepare
2021-03-27T09:33:22.302470 s1 fetch
2021-03-27T09:33:22.306730 s2 prepare
2021-03-27T09:33:22.889290 s2 fetch
2021-03-27T09:33:22.907777 s3 prepare
2021-03-27T09:33:22.909769 s3 fetch

Note:

• The s1 prepare step (using 1 enum) takes roughly 70 ms.
• The s2 prepare step (using 2 enums) takes roughly 600 ms.
• The s3 prepare step (using the same 2 enums) takes only 2 ms.

I've seen this same delay in several configurations:

• PostgreSQL 12.6 in ubuntu
• PostgreSQL 12.6 (in docker)
• PostgreSQL 13.2 (in docker)

The main question to start off with: is this expected behaviour?

I can imagine use of enums might require some cache initialisation for improved performance on subsequent operations, but it seems the delay increases significantly going from 1 to 2 enum columns.

[mivds]

As a brief update, I just tried running the example application against PostgreSQL 11.11 and am not seeing the delay in that case.

[elprans]

Try disabling JIT in PostgreSQL (jit = off)

[mivds]

Try disabling JIT in PostgreSQL (jit = off)

That seems to do the trick, thanks for the quick reply.

[llybin]

The issue is closed, but seems like the error in driver?