`sqlite`: `timeout` doesn't seem to work

[calestyo]

Bug report

Bug description:

Hey there.

(please read till the end... it does work with the sqlite3 utility, but not with Python’s sqlite)

With 3.13.2 on Debian unstable, it seems that sqlite.connect()’s timeout doesn't work as it should.

I have a small demo program:

#!/usr/bin/python3

import sqlite3
import sys
import time

print(f"con tmout: " + sys.argv[2])
con = sqlite3.connect("locks.db", autocommit=False, timeout=float(sys.argv[2]))
cur = con.cursor()

print(f"1st sleep: " + sys.argv[3])
time.sleep(int(sys.argv[3]))

cur.execute("CREATE TABLE IF NOT EXISTS locks (name TEXT PRIMARY KEY ON CONFLICT ROLLBACK) STRICT")

x = cur.execute("INSERT INTO locks (name) VALUES (?);", (sys.argv[1],) )
print(x.fetchall())

print(f"2nd sleep: " + sys.argv[4])
time.sleep(int(sys.argv[4]))

con.commit()

cur.close()
con.close()

• It uses autocommit=False, which uses DEFERRED transactions, which - AFAIU - means that the transaction only starts until the first, access, i.e. the execute() that would initially create the table and thus only after the first sleep.
• 4 args, first is the name value (which is a primary key and must be unique), second the timeout= of the connection, third is the sleep before the transaction starts, fourth the sleep right before the commit(),

My assumption would be that while the DB is locked because of a write transaction, any concurrent write transaction waits timeout= before it aborts.

Now when I start the script twice (at the same time), first e.g. with:

$ ./lock.py 1st_a 5 0 10

second with:

$ ./lock.py 2nd_a 500 0 0

I'd expect the second to wait for 500s and as the first sleeps only 10s, it should succeed.
However it immediately aborts with:

sqlite3.OperationalError: database is locked

I've seen #124510, but the explanation there was about the case of upgrading read transactions to write transactions, so what’s written here doesn't apply, and in fact it seems to just work as I expect with the sqlite3 utility:

First invocation:

$ sqlite3 locks.db
sqlite> BEGIN DEFERRED;
sqlite> INSERT INTO locks (name) VALUES ('1st_b');

Second invocation (note that sqlite3’s .timeout uses milliseconds):

$ sqlite3 locks.db
sqlite> .timeout 10000
sqlite> INSERT INTO locks (name) VALUES ('2nd_b');

Doing this, the second one will block, until either the 10s have passed, or I do a COMMIT; in the first.

Any ideas why that doesn't work in Python?

Thanks,
Chris.

CPython versions tested on:

3.13

Operating systems tested on:

Linux

[calestyo]

It doesn't even work, when using PRAGMA busy_timeout = milliseconds;

[calestyo]

Also:

• The timeout in Python does seem to work, if the transaction was started (but not finished) by sqlite3.
• And it works with both DEFERRED and EXCLUSIVE transactions (in sqlite3).

[calestyo]

I tried a bit more to debug this:

• first adding some debugging output:

  def d(s):
      print(f"SQL: {s}")
  

  and later:

  con.set_trace_callback(d)
  

  But unlike the documentation seems to imply no messages are generated from any statements that result from the transaction management (otherwise I'd expect to see some BEGIN DEFERRED; or so.

• when using autocommit=True, which the docs recommend against, it does work as expected, when also adding some manual transactions like in:

  cur.execute("BEGIN DEFERRED;")
  x = cur.execute("INSERT INTO locks (name) VALUES (?);", (sys.argv[1],) )
  # ... the sleep, etc.
  cur.execute("COMMIT;")
  

  Interestingly, this does however not work, when I do the BEGIN… before the CREATE TABLE... no idea why,... cause it doesn't seem as if the sqlite3 utility would behave here as Python does.

[erlend-aasland]

In the OP you start both Python scripts using autocommit=False, implying implicitly opening transaction in both processes. OTOH, in your SQLite shell example, you open a transaction in the first process; for the second process, you seem to rely on SQLite's autocommit feature. If I repeat your SQLite shell exercise using explicit transaction management (similarly to what autocommit=False does implicitly), I get "Runtime error: database is locked (5)". Perhaps I'm misunderstanding what you are trying to do here. Perhaps you could try to reduce your repro to an absolute minimum, both for the Python script and the SQLite shell script.

But unlike the documentation seems to imply no messages are generated from any statements that result from the transaction management (otherwise I'd expect to see some BEGIN DEFERRED; or so.

You won't be able to see the initial BEGIN DEFERRED when you're using PEP-249 compliant transaction management; a transaction is implicitly opened when you create the sqlite3.Connection object. IOW, your .set_trace_callback call is always too late.

when using autocommit=True, which the docs recommend against [...]

Where in the docs do we explicitly recommend against using autocommit=True? IIRC, we only recommend autocommit=False. autocommit=True is perfectly fine (it is often my preferred setting).

The reason we recommend autocommit=False is because the sqlite3 stdlib module aims to be PEP-249 compliant.

The only problematic setting is the current default: autocommit=None.

[calestyo]

In the OP you start both Python scripts using autocommit=False, implying implicitly opening transaction in both processes. OTOH, in your SQLite shell example, you open a transaction in the first process; for the second process, you seem to rely on SQLite's autocommit feature.

autocommit=False means not to use SQLite’s autocommit, but Python does it's own implicit transaction management, right?

In the 2nd shell process, it uses SQLite’s autocommit but that doesn't really change anything (other than also opening a transaction), or does it?

You can just change the 2nd shell to also use an explicit BEGIN and it will still block for the time of the .timeout whereas it doesn't within Python.

If I repeat your SQLite shell exercise using explicit transaction management (similarly to what autocommit=False does implicitly), I get "Runtime error: database is locked (5)".

I do so, too, but only after the timeout of 10s has passed (and I don't get it, if I release the lock by ending the transaction in the the shell). In Python I get it immediately.

Perhaps I'm misunderstanding what you are trying to do here. Perhaps you could try to reduce your repro to an absolute minimum, both for the Python script and the SQLite shell script.

I think the shell one is already at the absolute minimum.... and well the Python one more or less to.

The point simply is, on the shell/sqlite3 the timeout is waited and only afterwards I get a "locked" error. In Python it doesn't wait for the timeout to pass (and thus has no chance that the lock gets released meanwhile).

Where in the docs do we explicitly recommend against using autocommit=True?

Okay you don't actively recommend against it, but you do recommend for False ;-) ... which is kinda similar.

[erlend-aasland]

Okay you don't actively recommend against it, but you do recommend for False ;-) ... which is kinda similar.

I profoundly disagree with this.

You can just change the 2nd shell to also use an explicit BEGIN and it will still block for the time of the .timeout whereas it doesn't within Python.

I did, and I got the "database is locked" error.

[calestyo]

I did, and I got the "database is locked" error.

Immediately or after 10s?

The point/bug is... in Python, the timeout is ignored, in sqlite3 it's not.

[erlend-aasland]

The point/bug is... in Python, the timeout is ignored, in sqlite3 it's not.

Since we're directly calling sqlite3_busy_timeout immediately after opening a connection, I seriously doubt that it is ignored:

cpython/Modules/_sqlite/connection.c

Lines 258 to 268 in e7980ba

	// Create and configure SQLite database object.
	sqlite3 *db;
	int rc;
	Py_BEGIN_ALLOW_THREADS
	rc = sqlite3_open_v2(PyBytes_AS_STRING(bytes), &db,
	SQLITE_OPEN_READWRITE | SQLITE_OPEN_CREATE |
	(uri ? SQLITE_OPEN_URI : 0), NULL);
	if (rc == SQLITE_OK) {
	(void)sqlite3_busy_timeout(db, (int)(timeout*1000));
	}
	Py_END_ALLOW_THREADS

BTW:

• sqlite3: the Python stdlib module
• SQLite: the underlying SQLite library

[erlend-aasland]

I tried your repro again, with added "fprintf debugging" for the sqlite3_open_v2 result code:

$ time ./python.exe busy.py 1st_a 5 0 10
con tmout: 5
rc=0
1st sleep: 0
[]
2nd sleep: 10
./python.exe busy.py 1st_a 5 0 10  0.04s user 0.01s system 0% cpu 10.070 total
$ time ./python.exe busy.py 2nd_a 500 0 0
con tmout: 500
rc=0
1st sleep: 0
[]
2nd sleep: 0
./python.exe busy.py 2nd_a 500 0 0  0.03s user 0.02s system 0% cpu 10.327 total

This harmonises with your expectations from the OP, quoting:

I'd expect the second to wait for 500s and as the first sleeps only 10s, it should succeed.

Perhaps the issue you are seeing is in your environment?