Thanks for the quick reply! It does appear to be an environment issue on my end then.
I've already tried a few things: - Postgres 12 - Python 3.7 So far no dice. This was all within docker though, I'll try a few more things outside of the docker environment and report back. On Thursday, 25 March 2021 at 14:02:29 UTC+1 Mike Bayer wrote: > Hi there - > > thanks for the clear example. I just ran it against a several PG > databases, including a PG 13 and PG 12 on the local network, and I am not > observing any delay of that magnitude, SQL output with timestamps > follow. > > what OS are you running on ? I would say you might want to try > replicating these commands to plain asyncpg, but that will not necessarily > produce the same sequence as we use prepared statements explicitly in all > cases, or try running the equivalent commands with psycopg2 to see if > there's some database-specific issue going on. but you're running against > a vanilla docker container so that's a little strange, try running the > script from your workstation instead perhaps. > > 2021-03-25 08:56:24,722 INFO sqlalchemy.engine.Engine BEGIN (implicit) > 2021-03-25 08:56:24,723 INFO sqlalchemy.engine.Engine INSERT INTO "TableA" > (a) VALUES (%s) RETURNING "TableA".id > 2021-03-25 08:56:24,723 INFO sqlalchemy.engine.Engine [generated in > 0.00023s] ('ONE',) > 2021-03-25 08:56:24,754 DEBUG sqlalchemy.engine.Engine Col ('id',) > 2021-03-25 08:56:24,754 DEBUG sqlalchemy.engine.Engine Row (1,) > 2021-03-25 08:56:24,754 INFO sqlalchemy.engine.Engine COMMIT > 2021-03-25 08:56:24,758 INFO sqlalchemy.engine.Engine BEGIN (implicit) > 2021-03-25 08:56:24,759 INFO sqlalchemy.engine.Engine INSERT INTO "TableB" > (b, c) VALUES (%s, %s) RETURNING "TableB".id > 2021-03-25 08:56:24,759 INFO sqlalchemy.engine.Engine [generated in > 0.00019s] ('THREE', 'FIVE') > 2021-03-25 08:56:24,767 DEBUG sqlalchemy.engine.Engine Col ('id',) > 2021-03-25 08:56:24,767 DEBUG sqlalchemy.engine.Engine Row (1,) > 2021-03-25 08:56:24,768 INFO sqlalchemy.engine.Engine COMMIT > 2021-03-25 08:56:24,770 INFO sqlalchemy.engine.Engine BEGIN (implicit) > 2021-03-25 08:56:24,771 INFO sqlalchemy.engine.Engine INSERT INTO "TableB" > (b, c) VALUES (%s, %s) RETURNING "TableB".id > 2021-03-25 08:56:24,771 INFO sqlalchemy.engine.Engine [cached since > 0.01149s ago] ('FOUR', 'SIX') > 2021-03-25 08:56:24,772 DEBUG sqlalchemy.engine.Engine Col ('id',) > 2021-03-25 08:56:24,772 DEBUG sqlalchemy.engine.Engine Row (2,) > 2021-03-25 08:56:24,772 INFO sqlalchemy.engine.Engine COMMIT > > > On Thu, Mar 25, 2021, at 8:31 AM, Michaël Van de Steene wrote: > > Hi everyone, > > We recently started using sqlalchemy in combination with asyncpg and are > observing some behaviour we can't quite figure out. I hope this is the > right place to get help, if it would be better addressed elsewhere please > let me know. > > To frame the issue, we have a table with several enum columns. The first > time we access this table, there is a roughly 600 ms delay before any > results are returned. This seems to apply both for insert and select > operations. After that first access, everything seems speedy returning in > just a few milliseconds. > > I've created a short example application to show this problem: > import asyncio > import enum > from sqlalchemy import Enum, Column, Integer > from sqlalchemy.ext.asyncio import AsyncSession, create_async_engine > from sqlalchemy.ext.declarative import declarative_base > from sqlalchemy.orm import sessionmaker > > 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): > engine = create_async_engine(db_url, echo="debug") > Session = sessionmaker(engine, expire_on_commit=False, > class_=AsyncSession) > > async with engine.begin() as conn: > await conn.run_sync(Base.metadata.drop_all) > await conn.run_sync(Base.metadata.create_all) > > async with Session() as session: > async with session.begin(): > session.add(RecordA(a=A.ONE)) > async with session.begin(): > session.add(RecordB(b=B.THREE, c=C.FIVE)) > async with session.begin(): > session.add(RecordB(b=B.FOUR, c=C.SIX)) > > > asyncio.run(main( > "postgresql+asyncpg://postgres:exa...@host.docker.internal/postgres")) > > The logging of the three insert operations shows: > 2021-03-25 12:14:10,224 INFO sqlalchemy.engine.Engine BEGIN (implicit) > 2021-03-25 12:14:10,225 INFO sqlalchemy.engine.Engine INSERT INTO "TableA" > (a) VALUES (%s) RETURNING "TableA".id > 2021-03-25 12:14:10,225 INFO sqlalchemy.engine.Engine [generated in > 0.00011s] ('ONE',) > 2021-03-25 12:14:10,296 DEBUG sqlalchemy.engine.Engine Col ('id',) > 2021-03-25 12:14:10,296 DEBUG sqlalchemy.engine.Engine Row (1,) > 2021-03-25 12:14:10,296 INFO sqlalchemy.engine.Engine COMMIT > 2021-03-25 12:14:10,299 INFO sqlalchemy.engine.Engine BEGIN (implicit) > 2021-03-25 12:14:10,299 INFO sqlalchemy.engine.Engine INSERT INTO "TableB" > (b, c) VALUES (%s, %s) RETURNING "TableB".id > 2021-03-25 12:14:10,299 INFO sqlalchemy.engine.Engine [generated in > 0.00012s] ('THREE', 'FIVE') > 2021-03-25 12:14:10,906 DEBUG sqlalchemy.engine.Engine Col ('id',) > 2021-03-25 12:14:10,906 DEBUG sqlalchemy.engine.Engine Row (1,) > 2021-03-25 12:14:10,906 INFO sqlalchemy.engine.Engine COMMIT > 2021-03-25 12:14:10,924 INFO sqlalchemy.engine.Engine BEGIN (implicit) > 2021-03-25 12:14:10,924 INFO sqlalchemy.engine.Engine INSERT INTO "TableB" > (b, c) VALUES (%s, %s) RETURNING "TableB".id > 2021-03-25 12:14:10,924 INFO sqlalchemy.engine.Engine [cached since 0.625s > ago] ('FOUR', 'SIX') > 2021-03-25 12:14:10,926 DEBUG sqlalchemy.engine.Engine Col ('id',) > 2021-03-25 12:14:10,926 DEBUG sqlalchemy.engine.Engine Row (2,) > 2021-03-25 12:14:10,926 INFO sqlalchemy.engine.Engine COMMIT > > I've highlighted the timestamps showing the 600 ms delay in red. > It seems as if: > > - An insert with just 1 enum does not incur delay > - An insert with 2 enums incurs delays > - A subsequent insert using those same enums doesn't incur delay > > I'm at a loss to explain this behaviour. As I mentioned we're quite new to > SQLAlchemy. Is there anything we're doing wrong? > > The output is generated using: > > - PostgreSQL 13.2 > - Python 3.9.2 > - SQLAlchemy 1.4.2 > - Asyncpg 0.22.0 > > > Finally, run instructions using docker just in case it can help to quickly > reproduce: > > 1. Save the example as `asyncpg_enum.py` in the current directory > 2. Run docker run -d --name=postgres -e POSTGRES_PASSWORD="example" -p > 5432:5432 postgres > 3. Run docker run -it -v ${PWD}/asyncpg_enum.py:/asyncpg_enum.py > python bash -c 'pip install sqlalchemy asyncpg && python /asyncpg_enum.py' > > Any insight or things to check would be appreciated. > > Thanks, > Michael > > > -- > SQLAlchemy - > The Python SQL Toolkit and Object Relational Mapper > > http://www.sqlalchemy.org/ > > To post example code, please provide an MCVE: Minimal, Complete, and > Verifiable Example. See http://stackoverflow.com/help/mcve for a full > description. > --- > You received this message because you are subscribed to the Google Groups > "sqlalchemy" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to sqlalchemy+...@googlegroups.com. > To view this discussion on the web visit > https://groups.google.com/d/msgid/sqlalchemy/65748bd4-bea6-4e07-b7ce-c1a8c5a91c98n%40googlegroups.com > > <https://groups.google.com/d/msgid/sqlalchemy/65748bd4-bea6-4e07-b7ce-c1a8c5a91c98n%40googlegroups.com?utm_medium=email&utm_source=footer> > . > > > -- SQLAlchemy - The Python SQL Toolkit and Object Relational Mapper http://www.sqlalchemy.org/ To post example code, please provide an MCVE: Minimal, Complete, and Verifiable Example. See http://stackoverflow.com/help/mcve for a full description. --- You received this message because you are subscribed to the Google Groups "sqlalchemy" group. To unsubscribe from this group and stop receiving emails from it, send an email to sqlalchemy+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/sqlalchemy/8c817a6b-8e9b-41bd-940b-c91ceb6081a3n%40googlegroups.com.