Aiosqlite returns instantly `Database is Locked` error, even if timeout is 30 s

[qarmin]

Description

When running random inserting, deleting, selecting, updating in app that is running multiple times in pararrel, then sometimes I got "Database is Locked" error.

I set database timeout time to 30s

I run app in parallel with this code (12 means number of threads)

seq 12 | parallel -u -N0 -P12 python3 scratch_1.py | grep -E 'took|locked|EXCEPTION|Error' |& tee  aiosqlite_none.txt

When I run app, after a while I see that some of commands exeutes in > 10s when most of the time rest operations take usually < 10ms to execute

140131560632768 delete - took 38.721323013305664 ms
140131560632768 update - took 4.200935363769531 ms
140131560632768 delete - took 4.871129989624023 ms
140131560632768 insert - took 11.445760726928711 ms
140131560632768 delete - took 5.630016326904297 ms
140131560632768 delete - took 4.244804382324219 ms
140131560632768 select - took 3.5469532012939453 ms
140131560632768 select - took 2.2268295288085938 ms
140131560632768 delete - took 16563.55047225952 ms

This is likely expected with sqlite, because same problems I got with python sqlite and rust diesel sqlite versions.

The problem is, that sometimes I got instant sqlite3 operational error(Database is locked message)

139769081631168 update - took 1.9054412841796875 ms
139769081631168 update - took 1.8732547760009766 ms
139769081631168 insert - took 1.6071796417236328 ms
139769081631168 insert - took 1.1374950408935547 ms
FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF insert - took 4006.369113922119 ms
GOT EXCEPTION, trying again - retries number 2   <------ Here database shows, that first time executing command  was unsuccessful(wait time before next check is 2s)
GOT EXCEPTION, trying again - retries number 1 <------ Another unsuccessful executing and again 2s sleep before next check
GOT EXCEPTION, no more to try
EXCEPTION database is locked OperationalError 140684239561152 delete - took 4006.1073303222656 ms <-------- 4s = 2s sleep + 2s sleep + 6ms executing - so there is missing 30s timeout
140684239561152 delete - took 4006.4618587493896 ms
FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF delete - took 4006.4618587493896 ms

There is no 30s timeout here, but should be.

Almost same code I tried with python sqlite and rust diesel sqlite and I never had similar problems, so that is why I think that this is a problem with this library

Code

• aiosqlite version with problems - aiosqlite.py.txt
• sqlite version without problems - sqlite.py.txt

Results

• aiosqlite time results - aiosqlite_none.txt
• asqlite time results - sqlite_none.txt

Details

• OS: Ubuntu 22.04
• Python version: 3.10
• aiosqlite version: 0.19.0/0.18.0
• Can you repro on 'main' branch? - not tried yet, but almost sure that still happens there
• Can you repro in a clean virtualenv? - yes, with python 3.9, but I had same problem

[jbaiter]

I'm encountering the same issue, I have both the timeout parameter on the connect call and the PRAGMA busy_timeout set to 30 seconds, but when concurrent writes (from multiple threads with each their own connection) happen, .execute returns immediately with a Database is locked

[buxx]

Same problem here !

[buxx]

I spent a lot of time on this behavior. I am not an DB expert, so I read several documentation and I understood them as best I could. I can make this resume:

From Help understanding the effect of BEGIN IMMEDIATE discussion:

By default, BEGIN doesn't do anything to the database. It just makes a note, associated with its connection, that if you execute a SQL command that requires a transaction, instead of creating a transaction just for that one command, SQL should start a multi-statement transaction which requires COMMIT or ROLLBACK.

The effect of this is that you can issue BEGIN, then read a data file or wait for user input, before you actually need the transaction, and SQL won't keep the database locked for that time.

Obviously, after the BEGIN, but before the operation which requires the database to be locked, another connection might sneak in and lock the database and still have it locked when your transaction should start. To avoid this, use BEGIN IMMEDIATE, which means you'll never get that situation, but also that you are keeping the database locked before you actually need it, which will annoy other programs or users.

The following script help to see it:

import asyncio
import time

import aiosqlite

TIMEOUT = 10

async def main(start):
    async with aiosqlite.connect(
        'test.db',
        isolation_level=None,
        timeout=TIMEOUT,
    ) as connection:
        print(f"{time.time() - start:.5f} Main: Create table")
        await connection.execute("CREATE TABLE IF NOT EXISTS MyTable(id TEXT, data1 TEXT, data2 TEXT)")

    lock = asyncio.Lock()
    await lock.acquire()

    async def connect_begin_read_sleep_insert():
        try:
            async with aiosqlite.connect(
                'test.db',
                isolation_level=None,
                timeout=TIMEOUT,
            ) as connection:
                print(f"{time.time() - start:.5f} Task1: begin")
                # await connection.execute("BEGIN IMMEDIATE")
                await connection.execute("BEGIN")
                print(f"{time.time() - start:.5f} Task1: begin done")
                print(f"{time.time() - start:.5f} Task1: select")
                await connection.execute("select * from MyTable")
                print(f"{time.time() - start:.5f} Task1: select done")
                lock.release()
                print(f"{time.time() - start:.5f} Task1: sleep 5s")
                await asyncio.sleep(5)
                print(f"{time.time() - start:.5f} Task1: sleep done")
                print(f"{time.time() - start:.5f} Task1: insert")
                await connection.execute("INSERT INTO MyTable VALUES (?, ?, ?)", ("a", "b", "c"))
                print(f"{time.time() - start:.5f} Task1: insert done")
        except Exception as exc:
            print(f"{time.time() - start:.5f} Task1: 🔥{exc}")
            

    async def connect_insert():
        await lock.acquire()
        try:
            async with aiosqlite.connect(
                'test.db',
                isolation_level=None,
                timeout=TIMEOUT,
            ) as connection:
                print(f"{time.time() - start:.5f} Task2: insert")
                await connection.execute("INSERT INTO MyTable VALUES (?, ?, ?)", ("d", "e", "f"))
                print(f"{time.time() - start:.5f} Task2: insert done")
        except Exception as exc:
            print(f"{time.time() - start:.5f} Task2: 🔥{exc}")
            

    task1 = asyncio.create_task(connect_begin_read_sleep_insert())
    task2 = asyncio.create_task(connect_insert())
    await task1
    await task2


if __name__ == "__main__":
    start = time.time()
    print(f"{time.time() - start:.5f} Start (timeout={TIMEOUT})")
    asyncio.run(main(start))
    print(f"{time.time() - start:.5f} End")

Which produce:

0.00000 Start (timeout=10)
0.00063 Main: Create table
0.00236 Task1: begin
0.00243 Task1: begin done
0.00243 Task1: select
0.00258 Task1: select done
0.00259 Task1: sleep 5s
0.00284 Task2: insert
5.00786 Task1: sleep done
5.00789 Task1: insert
5.00829 Task1: 🔥database is locked
5.04145 Task2: insert done
5.04192 End

Instead, by using BEGIN IMMEDIATE:

0.00000 Start (timeout=10)
0.00064 Main: Create table
0.00143 Task1: begin
0.00159 Task1: begin done
0.00159 Task1: select
0.00175 Task1: select done
0.00176 Task1: sleep 5s
0.00211 Task2: insert
5.00742 Task1: sleep done
5.00745 Task1: insert
5.00791 Task1: insert done
5.04849 Task2: insert done
5.04885 End

In my real world case, it can explain my database is locked. Because aiosqlite, by its threading encapsulation mechanism, permit this kind of situation (using implicit DEFERRED transaction, see SQLite Transaction).

I have more difficulties to understand if there is a link with the qarmin script as it use only one connection at time. Maybe, the internal python garbage collector sometime don't finished with connection in previous aiosqlite thread. Not sure at all ...