test_sqlite_isolation fails with Python 3.11

[mgorny]

When running tests with Python 3.11.0b3, I get the following failure:

$ python runtests.py 
Unable to import APSW extension tests, skipping.
Unable to import CockroachDB tests, skipping.
Unable to import sqlite C extension tests, skipping.
Unable to import mysql-connector, skipping mysql_ext tests.
Unable to import postgres extension tests, skipping.
Unable to import SQLCipher extension tests, skipping.
Unable to import sqlite extension tests, skipping.
.s.....................s..................................s.....................sss...........................................s.......ss.....................................s........ssss............................................s...................................s.........................................................................s..................................................................................................................................................................ssss........................................ss.............................s..................s...........ss............s...s.........s....ss......s..............s..............................................................ss.......................E............ssssssss.....................................sss.......ssssssssssssss.....s..................s..ss..............................
======================================================================
ERROR: test_sqlite_isolation (tests.db_tests.TestSqliteIsolation.test_sqlite_isolation)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/peewee/tests/db_tests.py", line 461, in test_sqlite_isolation
    self.assertEqual(curs.fetchone()[0], 0)
                     ~~~~~~~~~~~~~~~^^^
TypeError: 'NoneType' object is not subscriptable

----------------------------------------------------------------------
Ran 894 tests in 5.487s

FAILED (errors=1, skipped=65)

[coleifer]

I don't see anything in the python 3.11 changelog that looks promising, any ideas?

[mgorny]

I'm going to try bisecting it.

[mgorny]

And here it is:

python/cpython@3df0fc8

commit 3df0fc89bc2714f5ef03e36a926bc795dcd5e05a
Author: Erlend Egeberg Aasland <erlend.aasland@innova.no>
Date:   Wed Aug 25 12:28:47 2021 +0200

    bpo-44976: Lazy creation of sqlite3 result rows (GH-27884)

 Modules/_sqlite/cursor.c | 84 +++++++++++++++++-------------------------------
 Modules/_sqlite/cursor.h |  3 --
 2 files changed, 29 insertions(+), 58 deletions(-)

[coleifer]

Thanks @mgorny very nice! My sense is that this may be a bug in sqlite3 (cc @erlend-aasland if you see this).

[erlend-aasland]

Can you report this on the CPython bug tracker? Please include a minimal (bare-bones) reproducer and as much information about your environment as possible.

Thanks!

[coleifer]

Sure I'll report and send a test if it's indeed a cpython issue. My sense is that it is but I'll let you know early next week

[erlend-aasland]

Great, thanks.

FYI, beta 4 is over-due, but is currently on hold bco. release blockers. I've notified the RM about this (possible) issue; if we could pin-point a minimal reproducer pretty quick, we could add this to the beta 4 release blockers, so we'd get a fix in the upcoming (b4) release.

I've tried to create a repro, but it's a little bit hard, since I've never used peewee, and I don't know its internal workings :(

[coleifer]

No worries, I'll take a look tomorrow (Mon) morning and let you know asap. Thx!

[coleifer]

Welp, I have managed to reproduce and think it has something to do with cursor garbage collection. Something quite strange is going on that I haven't so far experienced in all the time I've used Python. Here's what I've observed with peewee:

• Peewee test fails when run by itself
• If I insert a breakpoint right before line 461 and then "continue", the test is passing(?)
• If I insert a breakpoint right before line 461 and then "next", the test fails(?)
• If I insert a time.sleep(1) right before line 461, the test fails

Example of breakpoint + continue -> passing:

> /home/charles/tmp/py311/src/peewee/tests/db_tests.py(461)test_sqlite_isolation()
-> curs = new_db.execute_sql('SELECT COUNT(*) FROM users')
(Pdb) c
.
----------------------------------------------------------------------
Ran 1 test in 1.122s

Example of breakpoint + next -> fails again:

> /home/charles/tmp/py311/src/peewee/tests/db_tests.py(461)test_sqlite_isolation()
-> curs = new_db.execute_sql('SELECT COUNT(*) FROM users')
(Pdb) n
> /home/charles/tmp/py311/src/peewee/tests/db_tests.py(462)test_sqlite_isolation()
-> self.assertEqual(curs.fetchone()[0], 0)
(Pdb) n
TypeError: 'NoneType' object is not subscriptable

I cannot understand why it is passing when there's a breakpoint and then I select "continue" but using "next" makes it fail again!

---

Repro with stdlib sqlite3

Here is my repro. It took a while to get it to reproduce, but I had a feeling it had something to do (possibly) with garbage collection or cursors. Keeping the cursors around in memory seems to cause the problem to manifest, but if you comment-out the line indicated below then the tests will pass. Note that Peewee doesn't do anything weird like keep the cursors in memory, this was just the first way I've been able to successfully reproduce the issue. @erlend-aasland

import glob
import os
import sqlite3

filename = '/tmp/test.db'
for f in glob.glob(filename + '*'):
    os.unlink(f)  # Cleanup anything from prev run(s).

CURSORS = {}

def sql(conn, sql, *params):
    curs = conn.cursor()
    curs.execute(sql, params)
    CURSORS[id(sql)] = curs  # COMMENT THIS OUT AND TEST WILL PASS.
    return curs

# Set up database w/some sample rows. Peewee sets isolation-level to None as we
# want to manage all transaction state ourselves, rather than use sqlite3's
# somewhat unusual semantics.
db = sqlite3.connect(filename, isolation_level=None)
db.execute('create table users (id integer not null primary key, '
           'username text not null)')
sql(db, 'insert into users (username) values (?), (?), (?)', 'u1', 'u2', 'u3')
db.commit()

# On 2nd connection verify rows are visible, then delete them.
new_db2 = sqlite3.connect(filename, isolation_level=None)
assert sql(new_db2, 'select count(*) from users').fetchone()[0] == 3
assert sql(new_db2, 'delete from users').rowcount == 3

# Back in original connection, create 2 new users.
sql(db, 'begin')
sql(db, 'insert into users (username) values (?)', 'u4')
sql(db, 'insert into users (username) values (?)', 'u5')

# 2nd connection cannot see uncommitted changes.
# NOTE: this is the line that fails.
assert sql(new_db2, 'select count(*) from users').fetchone()[0] == 0

# Original conn can see its own changes.
assert sql(db, 'select count(*) from users').fetchone()[0] == 2
db.commit()

# Now the 2nd conn can see the changes.
assert sql(new_db2, 'select count(*) from users').fetchone()[0] == 2

Lastly, just as a sanity-check, the above script runs without error on Python 2.7, 3.6, 3.9 and 3.10 -- it only fails on 3.11.0b3.

[coleifer]

@erlend-aasland - I've created a new ticket on the CPython issue tracker, linked above python/cpython#94028 . As I mentioned on the cpython issue, this really is bizarre:

What is doubly-confusing about this error is that, when the failure occurs, the SQL being executed should definitely NOT be returning None from the call to fetchone(). If the table did not exist, we would get a different error from Sqlite. If the table does exist and we just can't see any rows, then we should be getting 0 (or possibly 2) as the test asserts. Instead, the fetchone() is returning None.

[coleifer]

Since this seems to me quite definitively a CPython / sqlite3 issue, I will close here.

[erlend-aasland]

Thanks a lot for your investigations, @coleifer! I've marked python/cpython#94028 as a release blocker. Hopefully we'll find a solution within the next few days.

[erlend-aasland]

I have a fix for this in python/cpython#94042. If you have the possibility to test the fix before I merge it, I'd appreciate it, @mgorny.

[mgorny]

I can confirm that applying this patch to cpython causes peewee tests to pass.

[mgorny]

(I've applied it on top of 3.11.0b3)

[erlend-aasland]

Great, thank you!

[coleifer]

Thank you both @mgorny and @erlend-aasland for the help finding and fixing this.

[erlend-aasland]

FYI, the fix has been merged and will appear in the upcoming beta 4 release.