Modified statements in "before_cursor_executes" break SQLite update assertions w/ declarative_base [1.2.14]

[montanalow]

If you return a modified version of the sql statement in a before_cursor_execute event, UPDATEs to models will fail against SQLite, but not against other RDBMs like Postgres.

It's common to add watermarking comments to all queries that explain the origin for use during debugging/load optimization. e.g.

@event.listens_for(engine, "before_cursor_execute", retval=True)
def watermark_sql_calls(conn, cursor, statement, parameters, context, executemany):
    statement = "/* %s */\n%s" % ("this is a test", statement)
    return statement, parameters

Complete failure example:

import datetime
import sqlalchemy
from sqlalchemy import Column, Integer, DateTime, event
from sqlalchemy.ext.declarative import declarative_base
from sqlalchemy.orm import sessionmaker, scoped_session

engine = sqlalchemy.create_engine('sqlite:///test.sqlite').execution_options(autocommit=True)
Session = scoped_session(sessionmaker(bind=engine))

# Removing this event listener will fix the problem
@event.listens_for(engine, "before_cursor_execute", retval=True)
def watermark_sql_calls(conn, cursor, statement, parameters, context, executemany):
    statement = "/* %s */\n%s" % ("watermarking bug", statement)
    return statement, parameters

Base = declarative_base()
class Foo(Base):
    __tablename__ = 'foo'
    id = Column(Integer, primary_key=True)
    updated_at = Column(DateTime)
Base.metadata.create_all(engine)

foo = Foo()
session = Session()
session.add(foo)  
session.commit()

foo.updated_at = datetime.datetime.now()
session.commit()

results in a failed row count update assertion:

  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 954, in commit
    self.transaction.commit()
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 467, in commit
    self._prepare_impl()
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 447, in _prepare_impl
    self.session.flush()
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2313, in flush
    self._flush(objects)
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2440, in _flush
    transaction.rollback(_capture_exception=True)
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/util/compat.py", line 249, in reraise
    raise value
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 2404, in _flush
    flush_context.execute()
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 395, in execute
    rec.execute(self)
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 560, in execute
    uow
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj
    mapper, table, update)
  File "/Users/montanalow/.pyenv/versions/3.6.6/envs/lore/lib/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 797, in _emit_update_statements
    (table.description, len(records), rows))
sqlalchemy.orm.exc.StaleDataError: UPDATE statement on table 'foo' expected to update 1 row(s); -1 were matched.

[zzzeek]

SQLAlchemy doesn't calculate that rowcount, the driver does, so this is a sqlite3 bug that should be posted to bugs.python.org. It is a common technique in the sqlite3 driver that they parse SQL statements in order to determine if certain actions should be taken, an example of a previous issue with this is https://bugs.python.org/issue21718. So for this issue, here's the test case:

import sqlite3

conn = sqlite3.connect(":memory:")

cursor = conn.cursor()

cursor.execute("""
CREATE TABLE foo (
    id INTEGER NOT NULL,
    updated_at DATETIME,
    PRIMARY KEY (id)
)
""")

cursor.execute("""
/* watermarking bug */
INSERT INTO foo (id, updated_at) VALUES (?, ?)
""", [1, None])


cursor.execute("""
    UPDATE foo SET updated_at=? WHERE foo.id = ?
""", ('2018-12-02 14:55:57.169785', 1))

assert cursor.rowcount == 1

cursor.execute("""
    /* watermarking bug */
    UPDATE foo SET updated_at=? WHERE foo.id = ?
""", ('2018-12-03 14:55:57.169785', 1))

assert cursor.rowcount == 1

for workaround here, turn off the "sane rowcount" flag of the dialect to disable these checks:

engine = sqlalchemy.create_engine('sqlite://', echo=True)
engine.dialect.supports_sane_rowcount = False
engine.dialect.supports_sane_multi_rowcount = False  # for executemany()

[zzzeek]

please forward to bugs.python.org and use that workaround for now, there's no other action to be taken on this end, reopen if necessary. thanks!

[montanalow]

Thank you. I've reported upstream:
https://bugs.python.org/issue35398

[erlend-aasland]

FYI, fixes have now landed for...:

• main (Python 3.12): gh-79579: Improve DML query detection in sqlite3 python/cpython#93623
• Python 3.11: [3.11] gh-79579: Improve DML query detection in sqlite3 (GH-93623) python/cpython#93800
• Python 3.10: [3.10] gh-79579: Improve DML query detection in sqlite3 (GH-93623) python/cpython#93801