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:[email protected]/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 [email protected].
> 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 [email protected].
To view this discussion on the web visit
https://groups.google.com/d/msgid/sqlalchemy/8c817a6b-8e9b-41bd-940b-c91ceb6081a3n%40googlegroups.com.
