session.get() behavior after session.expire()

[ljiatu]

The doc for session.get() says: "`Session.get()... If the given primary key identifier is present in the local identity map, the object is returned directly from this collection and no SQL is emitted, unless the object has been marked fully expired. ..."

So I tried to do session.expire() and then session.get() like below:

import asyncio

from sqlalchemy import Column, DateTime, Integer, func
from sqlalchemy import String
from sqlalchemy.ext.asyncio import AsyncSession
from sqlalchemy.ext.asyncio import create_async_engine
from sqlalchemy.ext.declarative import declarative_base
from sqlalchemy.orm import sessionmaker

Base = declarative_base()


class A(Base):
    __tablename__ = "a"

    id = Column(Integer, primary_key=True)
    created_at = Column(DateTime(timezone=True), default=func.now(), nullable=False)
    data = Column(String)


async def async_main():
    engine = create_async_engine(
        "postgresql+asyncpg://localhost/platform_dev",
        echo=True,
    )

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

    session_maker = sessionmaker(
        engine, class_=AsyncSession, expire_on_commit=False
    )

    obj = A(id=1, data="a1")
    async with session_maker() as session:
        async with session.begin():
            session.add(obj)

        session.expire(obj)

        A1 = await session.get(A, obj.id)
        print("A1")
        print(A1.__dict__)


asyncio.run(async_main())

And a SQL statement is issued as expected, but an error was also thrown. Full output:

2021-04-02 00:44:50,187 INFO sqlalchemy.engine.Engine select version()
2021-04-02 00:44:50,187 INFO sqlalchemy.engine.Engine [raw sql] ()
2021-04-02 00:44:50,190 INFO sqlalchemy.engine.Engine select current_schema()
2021-04-02 00:44:50,190 INFO sqlalchemy.engine.Engine [raw sql] ()
2021-04-02 00:44:50,191 INFO sqlalchemy.engine.Engine show standard_conforming_strings
2021-04-02 00:44:50,191 INFO sqlalchemy.engine.Engine [raw sql] ()
2021-04-02 00:44:50,193 INFO sqlalchemy.engine.Engine BEGIN (implicit)
2021-04-02 00:44:50,194 INFO sqlalchemy.engine.Engine select relname from pg_class c join pg_namespace n on n.oid=c.relnamespace where pg_catalog.pg_table_is_visible(c.oid) and relname=%s
2021-04-02 00:44:50,194 INFO sqlalchemy.engine.Engine [generated in 0.00021s] ('a',)
2021-04-02 00:44.50 [info     ] Query completed. Total time: 1.6ms.
Query: select relname from pg_class c join pg_namespace n... [truncated]

2021-04-02 00:44:50,196 INFO sqlalchemy.engine.Engine
DROP TABLE a
2021-04-02 00:44:50,196 INFO sqlalchemy.engine.Engine [no key 0.00014s] ()
2021-04-02 00:44.50 [info     ] Query completed. Total time: 2.6ms.
Query:  DROP TABLE a

2021-04-02 00:44:50,199 INFO sqlalchemy.engine.Engine select relname from pg_class c join pg_namespace n on n.oid=c.relnamespace where pg_catalog.pg_table_is_visible(c.oid) and relname=%s
2021-04-02 00:44:50,199 INFO sqlalchemy.engine.Engine [cached since 0.005372s ago] ('a',)
2021-04-02 00:44.50 [info     ] Query completed. Total time: 1.1ms.
Query: select relname from pg_class c join pg_namespace n... [truncated]

2021-04-02 00:44:50,201 INFO sqlalchemy.engine.Engine
CREATE TABLE a (
	id SERIAL NOT NULL,
	created_at TIMESTAMP WITH TIME ZONE NOT NULL,
	data VARCHAR,
	PRIMARY KEY (id)
)


2021-04-02 00:44:50,201 INFO sqlalchemy.engine.Engine [no key 0.00014s] ()
2021-04-02 00:44.50 [info     ] Query completed. Total time: 5.6ms.
Query:  CREATE TABLE a ( 	id SERIAL NOT NULL,  	created_a... [truncated]

2021-04-02 00:44:50,206 INFO sqlalchemy.engine.Engine COMMIT
2021-04-02 00:44:50,210 INFO sqlalchemy.engine.Engine BEGIN (implicit)
2021-04-02 00:44:50,211 INFO sqlalchemy.engine.Engine INSERT INTO a (id, created_at, data) VALUES (%s, now(), %s)
2021-04-02 00:44:50,211 INFO sqlalchemy.engine.Engine [generated in 0.00031s] (1, 'a1')
2021-04-02 00:44.50 [info     ] Query completed. Total time: 2.2ms.
Query: INSERT INTO a (id, created_at, data) VALUES (%s, n... [truncated]

2021-04-02 00:44:50,214 INFO sqlalchemy.engine.Engine COMMIT
2021-04-02 00:44:50,215 INFO sqlalchemy.engine.Engine BEGIN (implicit)
2021-04-02 00:44:50,218 INFO sqlalchemy.engine.Engine SELECT a.id AS a_id, a.created_at AS a_created_at, a.data AS a_data
FROM a
WHERE a.id = %s
2021-04-02 00:44:50,218 INFO sqlalchemy.engine.Engine [generated in 0.00040s] (1,)
2021-04-02 00:44:50,219 INFO sqlalchemy.engine.Engine ROLLBACK
Traceback (most recent call last):
  File "script.py", line 125, in <module>
    asyncio.run(async_main())
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/usr/local/opt/python@3.8/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/Users/jiatu/workspace/alt/py/projects/platform-server/server/cli/create_dwolla_webhook.py", line 120, in async_main
    A1 = await session.get(A, obj.id)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/attributes.py", line 449, in __get__
    return self.impl.get(state, dict_)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/attributes.py", line 888, in get
    value = state._load_expired(state, passive)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/state.py", line 667, in _load_expired
    self.manager.expired_attribute_loader(self, toload, passive)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 1408, in load_scalar_attributes
    result = load_on_ident(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 363, in load_on_ident
    return load_on_pk_identity(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 522, in load_on_pk_identity
    session.execute(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/orm/session.py", line 1653, in execute
    result = conn._execute_20(statement, params or {}, execution_options)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1520, in _execute_20
    return meth(self, args_10style, kwargs_10style, execution_options)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 313, in _execute_on_connection
    return connection._execute_clauseelement(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1389, in _execute_clauseelement
    ret = self._execute_context(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1748, in _execute_context
    self._handle_dbapi_exception(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1933, in _handle_dbapi_exception
    util.raise_(exc_info[1], with_traceback=exc_info[2])
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 198, in raise_
    raise exception
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1705, in _execute_context
    self.dialect.do_execute(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 681, in do_execute
    cursor.execute(statement, parameters)
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 449, in execute
    self._adapt_connection.await_(
  File "/Users/jiatu/Library/Caches/pypoetry/virtualenvs/server-4z3-4eze-py3.8/lib/python3.8/site-packages/sqlalchemy/util/_concurrency_py3k.py", line 47, in await_only
    raise exc.MissingGreenlet(
sqlalchemy.exc.MissingGreenlet: greenlet_spawn has not been called; can't call await_() here. Was IO attempted in an unexpected place? (Background on this error at: http://sqlalche.me/e/14/xd2s)
sys:1: RuntimeWarning: coroutine 'AsyncAdapt_asyncpg_cursor._prepare_and_execute' was never awaited

If I replace expire() with expunge() then the error goes away (I'm expecting expunge to work anyways). So is this behavior with expire() expected?

Thanks for your help!

[zzzeek]

interesting, you awaited and....it should not raise for that. might be a bug.

[zzzeek]

oh... heh, no. Sorry, you are accessing obj.id. That isn't there because the object is expired; expiration checks if the row was deleted when you access it also. that's where your stack trace is.

[zzzeek]

    obj = A(id=1, data="a1")
    async with session_maker() as session:
        async with session.begin():
            session.add(obj)

            id_ = obj.id
        session.expire(obj)

        A1 = await session.get(A, id_)
        print("A1")
        print(A1.__dict__)

if there were a way to make this not as delicate, I would, but expiration is expiration ... :)

[ljiatu]

Oh gee, I'm sorry 🤦 .

I guess my question now is why expunge works...?

[zzzeek]

expunge didn't expire the data inside your object.

think of your object like this:

class Foo:
   pass

f1 = Foo()
f1.id = 5

then think of expire like this:

del f1.id

it's all about what's inside of obj.__dict__ or not. just look in there and you'll see what won't emit SQL, what will.

[ljiatu]

Ah ok makes sense. Thanks!