Skip to content

Slow introspection when using multiple custom types in a query #530

Closed
@tristan

Description

@tristan
  • asyncpg version: 0.20.1
  • PostgreSQL version: 12.1
  • Do you use a PostgreSQL SaaS? If so, which? Can you reproduce
    the issue with a local PostgreSQL install?
    : postgresql is installed locally on archlinux
  • Python version: 3.7.6 and 3.8.1
  • Platform: Linux 5.4.13-arch1-1
  • 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 have a few custom types (CREATE TYPE ...) in my database, and I'm running into issues where asyncpg's introspection stage on queries using 2 or more of these types are taking > 1 second to complete.

e.g.

add log_min_duration_statement = 500 to the default postgresql.conf

Create a database test with schema:

CREATE TYPE FOURBIGINTS AS (i0 BIGINT, i1 BIGINT, i2 BIGINT, i3 BIGINT);
CREATE TYPE NUMBERS_AS_WORDS AS ENUM (
    'zero', 'one', 'two', 'three', 'four'
);
CREATE TABLE bigthings (
    thing_id BIGSERIAL PRIMARY KEY,
    num FOURBIGINTS,
    words NUMBERS_AS_WORDS
);

and run the following code:

import asyncio
import asyncpg

async def main():
    con_args = {
        'dsn': 'postgres:///test',
        'ssl': None,
        'min_size': 10,
        'max_size': 10
    }
    pool = await asyncpg.create_pool(**con_args)

    async with pool.acquire() as con:
        await con.execute(
            """\
        INSERT INTO bigthings
        (num, words)
        VALUES ($1::FOURBIGINTS, $2::NUMBERS_AS_WORDS)
        """,
            (0, 0, 0, 0), 'one')

asyncio.run(main())

watching the logs (on my system sudo journalctl -u postgresql -f, will show something like:

2020-01-21 14:45:49.066 CET [118544] LOG:  duration: 1593.511 ms  execute __asyncpg_stmt_2__: WITH RECURSIVE typeinfo_tree(
            oid, ns, name, kind, basetype, has_bin_io, elemtype, elemdelim,
            range_subtype, elem_has_bin_io, attrtypoids, attrnames, depth)
        AS (
            SELECT
...
2020-01-21 14:45:49.066 CET [118544] DETAIL:  parameters: $1 = '{16584,16582}'

I've traced this back to the call to _introspect_types in connection.py.

From a bit of testing, it only happens if there are multiple custom types used in the query. e.g. if i change the query to simply be INSERT INTO bigthings (num) VALUES ($1::FOURBIGINTS), then everything is nice and fast as expected, or if i change the bigthings.words column to a VARCHAR, then there is no problem. But as soon as I include two or more custom types (e.g. 2 enum types or 2 tuple types, or a mix) then I see the slow downs.

Is there anything I can do to either remove the need for this introspection (e.g. giving asyncpg some hints about these types), or maybe I'm doing something wrong that I can correct?

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions