duckdb / sqlite_scanner

DuckDB extension to read and write to SQLite databases
MIT License
189 stars 19 forks source link

SQLite/DuckDB Concurrency Errors Within a Single Process #82

Closed breckcs closed 2 months ago

breckcs commented 5 months ago

What happens?

  1. Write to a SQLite database using a SQLite client.
  2. Reading concurrently from the same SQLite database within the same process leads to various errors:
    1. attempt to write a readonly database errors.
    2. A crash due to EXC_BAD_ACCESS (SIGBUS).
    3. database is locked errors.

I am unable to produce similar errors when reading concurrently with a SQLite client.

Six test scenarios are detailed below.

I'm happy to help with further debugging and/or updates to code or documentation related to this issue.

To Reproduce

  1. Clone duckdb_sqlite_scanner_concurrency_tests.
  2. Use Cargo to run each test individually.

:white_check_mark: 1) SQLite Writer, SQLite Reader, No WAL

Run the test:

cargo test test_sqlite_writer_sqlite_reader_no_wal -- --nocapture

It should pass:

...
SQLite COUNT : 9998
SQLite COUNT : 9999
SQLite COUNT : 10000
test tests::test_sqlite_writer_sqlite_reader_no_wal ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 5 filtered out; finished in 39.56s

:white_check_mark: 2) SQLite Writer, SQLite Reader, With WAL

Run the test:

cargo test test_sqlite_writer_sqlite_reader_with_wal -- --nocapture

It should pass:

...
SQLite COUNT : 9998
SQLite COUNT : 9999
SQLite COUNT : 10000
test tests::test_sqlite_writer_sqlite_reader_with_wal ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 5 filtered out; finished in 16.27s

:red_circle: 3) SQLite Writer, DuckDB Reader, No WAL

Run the test:

cargo test test_sqlite_writer_duckdb_reader_no_wal -- --nocapture

It should fail:

running 1 test
thread '<unnamed>' panicked at src/main.rs:194:84:
called `Result::unwrap()` on an `Err` value: DuckDBFailure(Error { code: Unknown, extended_code: 1 }, Some("Invalid Error: Failed to prepare query \"SELECT type FROM sqlite_master WHERE lower(name)=lower('users');\": attempt to write a readonly database"))

I don't expect DuckDB to be mutating anyting in this test, but even if I remove the READ_ONLY from the ATTACH statement, I get a similar error:

DuckDB COUNT : 627
thread '<unnamed>' panicked at src/main.rs:194:84:
called `Result::unwrap()` on an `Err` value: DuckDBFailure(Error { code: Unknown, extended_code: 1 }, Some("Invalid Error: Failed to prepare query \"SELECT ROWID FROM \"users\" WHERE ROWID BETWEEN 0 AND 122879\": attempt to write a readonly database"))

DuckDB is ultimately using the SQLite client to read, so this scenario should be equivalent to the first test scenario.

Questions:

  1. Is DuckDB opening the SQLite database in an incompatible mode?
  2. Does sqlite3.c used by both Rusqlite and duckdb-rs need to be binary compatible?

:red_circle: 4) SQLite Writer, DuckDB Reader, With WAL

Run the test:

cargo test test_sqlite_writer_duckdb_reader_with_wal -- --nocapture

The process crashes with a EXC_BAD_ACCESS (SIGBUS) error:

DuckDB COUNT : 1630
DuckDB COUNT : 1633
DuckDB COUNT : 1634
error: test failed, to rerun pass `--bin duckdb_sqlite_scanner_concurrency_tests`

Caused by:
  process didn't exit successfully: `/Users/cbreck/github/duckdb_sqlite_scanner_concurrency_tests/target/debug/deps/duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4 test_sqlite_writer_duckdb_reader_with_wal --nocapture` (signal: 10, SIGBUS: access to undefined memory)

If I run it in the debugger, I get the following console output:

2024-01-24 05:55:49.165465-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb9ParseInfoE, N6duckdb23CreateTableFunctionInfoE, N6duckdb23CreateTableFunctionInfoE.
2024-01-24 05:55:49.165892-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb9ParseInfoE, N6duckdb23CreateTableFunctionInfoE, N6duckdb23CreateTableFunctionInfoE.
2024-01-24 05:55:49.168720-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb12CatalogEntryE, N6duckdb16SQLiteTableEntryE, N6duckdb17TableCatalogEntryE.
2024-01-24 05:55:49.172696-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb12CatalogEntryE, N6duckdb16SQLiteTableEntryE, N6duckdb17TableCatalogEntryE.
2024-01-24 05:55:49.188474-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb12CatalogEntryE, N6duckdb16SQLiteTableEntryE, N6duckdb17TableCatalogEntryE.
2024-01-24 05:55:49.218949-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb12CatalogEntryE, N6duckdb16SQLiteTableEntryE, N6duckdb17TableCatalogEntryE.
2024-01-24 05:55:49.278716-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb12CatalogEntryE, N6duckdb16SQLiteTableEntryE, N6duckdb17TableCatalogEntryE.
2024-01-24 05:55:49.397928-0800 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4[31472:2612509] dynamic_cast error 2: One or more of the following type_info's has hidden visibility or is defined in more than one translation unit. They should all have public visibility. N6duckdb12CatalogEntryE, N6duckdb16SQLiteTableEntryE, N6duckdb17TableCatalogEntryE.
Exception: EXC_BAD_ACCESS (code=10, address=0x1085a57f0)

The call stack is as follows:

(lldb) thread backtrace
* thread #3, stop reason = EXC_BAD_ACCESS (code=10, address=0x1085a57f0)
  * frame #0: 0x0000000104462fac duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`walIndexAppend(pWal=0x000000011fa04c00, iFrame=626, iPage=8) at sqlite3.c:65512:30
    frame #1: 0x0000000104462098 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`walFrames(pWal=0x000000011fa04c00, szPage=4096, pList=0x000000012001c638, nTruncate=8, isCommit=1, sync_flags=10) at sqlite3.c:68303:10
    frame #2: 0x0000000104461814 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3WalFrames(pWal=0x000000011fa04c00, szPage=4096, pList=0x000000012001c638, nTruncate=8, isCommit=1, sync_flags=10) at sqlite3.c:68350:10
    frame #3: 0x000000010445fa68 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`pagerWalFrames(pPager=0x000000012000b400, pList=0x000000012001c638, nTruncate=8, isCommit=1) at sqlite3.c:59594:8
    frame #4: 0x000000010443b260 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3PagerCommitPhaseOne(pPager=0x000000012000b400, zSuper=0x0000000000000000, noSync=0) at sqlite3.c:62867:14
    frame #5: 0x000000010443b7b4 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3BtreeCommitPhaseOne(p=0x0000600002e140a0, zSuperJrnl=0x0000000000000000) at sqlite3.c:73975:10
    frame #6: 0x00000001044770fc duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`vdbeCommit(db=0x000000011f804da0, p=0x00000001100136d0) at sqlite3.c:86887:14
    frame #7: 0x0000000104476378 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3VdbeHalt(p=0x00000001100136d0) at sqlite3.c:87297:16
    frame #8: 0x000000010447cde8 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3VdbeExec(p=0x00000001100136d0) at sqlite3.c:93436:8
    frame #9: 0x000000010443eac0 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3Step(p=0x00000001100136d0) at sqlite3.c:90247:10
    frame #10: 0x0000000104438eb8 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`sqlite3_step(pStmt=0x00000001100136d0) at sqlite3.c:90308:16
    frame #11: 0x00000001029eeae8 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`rusqlite::raw_statement::RawStatement::step(self=0x000000016d82a8a8) at raw_statement.rs:106:18
    frame #12: 0x00000001029ff058 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`rusqlite::statement::Statement::execute_with_bound_parameters(self=0x000000016d82a8a0) at statement.rs:652:17
    frame #13: 0x00000001029ef470 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`rusqlite::statement::Statement::execute(self=0x000000016d82a8a0, params=([0] = 1612)) at statement.rs:114:9
    frame #14: 0x00000001029ee744 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`rusqlite::Connection::execute::{{closure}}::{{closure}}((null)=() @ 0x000000016d82a6af) at lib.rs:622:69
    frame #15: 0x00000001029ed5d8 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`core::result::Result<T,E>::and_then(self=(Ok = core::result::Result<(), rusqlite::error::Error>::Ok @ 0x000000016d82a788, Err = core::result::Result<(), rusqlite::error::Error>::Err @ 0x000000016d82a788), op=rusqlite::{impl#4}::execute::{closure#0}::{closure_env#0}<[i64; 1]> @ 0x000000016d82a7c8) at result.rs:1320:22
    frame #16: 0x00000001029ee6d8 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`rusqlite::Connection::execute::{{closure}}(stmt=rusqlite::statement::Statement @ 0x000000016d82a8a0) at lib.rs:622:34
    frame #17: 0x00000001029ed834 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`core::result::Result<T,E>::and_then(self=core::result::Result<rusqlite::statement::Statement, rusqlite::error::Error>::Ok @ 0x000000016d82a970, op=rusqlite::{impl#4}::execute::{closure_env#0}<[i64; 1]> @ 0x000000016d82a840) at result.rs:1320:22
    frame #18: 0x00000001029ee63c duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`rusqlite::Connection::execute(self=0x000000016d82aa50, sql="INSERT INTO users VALUES ('Alice', (?));", params=([0] = 1612)) at lib.rs:621:9
    frame #19: 0x0000000102a001f8 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`duckdb_sqlite_scanner_concurrency_tests::tests::sqlite_writer_duckdb_reader_with_wal::{{closure}} at main.rs:225:17
    frame #20: 0x00000001029eaf98 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::sys_common::backtrace::__rust_begin_short_backtrace(f=duckdb_sqlite_scanner_concurrency_tests::tests::sqlite_writer_duckdb_reader_with_wal::{closure_env#0} @ 0x000000016d82ac80) at backtrace.rs:154:18
    frame #21: 0x00000001029fb070 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}} at mod.rs:529:17
    frame #22: 0x00000001029fe180 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`<core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once(self=core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<duckdb_sqlite_scanner_concurrency_tests::tests::sqlite_writer_duckdb_reader_with_wal::{closure_env#0}, ()>> @ 0x000000016d82acd0, (null)=() @ 0x000000016d82accf) at unwind_safe.rs:272:9
    frame #23: 0x0000000102a05300 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::panicking::try::do_call(data=0x000000016d82ad78) at panicking.rs:552:40
    frame #24: 0x0000000102a05da4 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`__rust_try + 32
    frame #25: 0x0000000102a04910 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::panicking::try(f=core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<duckdb_sqlite_scanner_concurrency_tests::tests::sqlite_writer_duckdb_reader_with_wal::{closure_env#0}, ()>> @ 0x000000016d82ad98) at panicking.rs:516:19
    frame #26: 0x00000001029f9c70 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::thread::Builder::spawn_unchecked_::{{closure}} at panic.rs:142:14
    frame #27: 0x00000001029f9c64 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::thread::Builder::spawn_unchecked_::{{closure}} at mod.rs:528:30
    frame #28: 0x00000001029fba44 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`core::ops::function::FnOnce::call_once{{vtable.shim}}((null)=0x000060000031c0c0, (null)=() @ 0x000000016d82af67) at function.rs:250:5
    frame #29: 0x00000001045fd35c duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::sys::unix::thread::Thread::new::thread_start [inlined] <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once at boxed.rs:2007:9 [opt]
    frame #30: 0x00000001045fd350 duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::sys::unix::thread::Thread::new::thread_start [inlined] <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once at boxed.rs:2007:9 [opt]
    frame #31: 0x00000001045fd34c duckdb_sqlite_scanner_concurrency_tests-80eb8bd2605a4fd4`std::sys::unix::thread::Thread::new::thread_start at thread.rs:108:17 [opt]
    frame #32: 0x000000018b44a034 libsystem_pthread.dylib`_pthread_start + 136

It always fails in the walIndexAppend function in the sqlite3.c client.

DuckDB is ultimately using the SQLite client to read, so this scenario should be equivalent to the second test scenario.

Questions:

  1. Is DuckDB opening the SQLite database in an incompatible mode?
  2. Does sqlite3.c used by both Rusqlite and duckdb-rs need to be binary compatible?

I'm using RustRover as my debugger.

image

:red_circle: 5) DuckDB Writer, DuckDB Reader, No WAL

In an attempt to eliminate binary compatibility issues between the Rusqlite and duckdb-rs clients, I wrote to the SQLite database and read from the SQLite database using only the duckdb-rs client.

Run the test:

cargo test test_duckdb_writer_duckdb_reader_no_wal -- --nocapture

It fails with:

...
DuckDB COUNT : 360
DuckDB COUNT : 361
DuckDB COUNT : 362
thread '<unnamed>' panicked at src/main.rs:291:22:
called `Result::unwrap()` on an `Err` value: DuckDBFailure(Error { code: Unknown, extended_code: 1 }, Some("Invalid Error: Failed to execute query \"COMMIT\": database is locked"))
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
thread '<unnamed>' panicked at src/main.rs:317:84:
called `Result::unwrap()` on an `Err` value: DuckDBFailure(Error { code: Unknown, extended_code: 1 }, Some("Invalid Error: Failed to prepare query \"SELECT ROWID FROM \"users\" WHERE ROWID BETWEEN 0 AND 122879\": database is locked"))
thread 'tests::test_duckdb_writer_duckdb_reader_no_wal' panicked at src/main.rs:326:23:
called `Result::unwrap()` on an `Err` value: Any { .. }
test tests::test_duckdb_writer_duckdb_reader_no_wal ... FAILED

failures:

failures:
    tests::test_duckdb_writer_duckdb_reader_no_wal

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 5 filtered out; finished in 2.07s

There have been other reports of the database is locked error. See #78.

:red_circle: 6) DuckDB Writer, DuckDB Reader, With WAL

Just for completeness, I also used only the duckdb-rs client to read and write to the SQLite database with WAL model enabled. Note, I don't see a way to create the SQLite database with WAL enabled using the DuckDB client, so the database is first created using the Rusqlite client, then closed and opened with the duckdb-rs client before writing to it.

Run the test:

cargo test test_duckdb_writer_duckdb_reader_with_wal -- --nocapture

This fails with:

running 1 test
thread '<unnamed>' panicked at src/main.rs:395:18:
called `Result::unwrap()` on an `Err` value: DuckDBFailure(Error { code: Unknown, extended_code: 1 }, Some("Invalid Error: Failed to prepare query \"SELECT type FROM sqlite_master WHERE lower(name)=lower('users');\": database is locked"))

OS:

Mac OS X arm64

SQLite Version:

3.44.0

DuckDB Version:

0.9.2

DuckDB Client:

duckdb-rs (Rust)

Full Name:

Colin Breck

Affiliation:

Tesla

Have you tried this on the latest main branch?

Have you tried the steps to reproduce? Do they include all relevant data and configuration? Does the issue you report still appear there?

Mytherin commented 4 months ago

Thanks for the detailed report! I've pushed a fix in #83. The reason this appears to work in the Rust SQLite driver is because they specify a busy timeout by default. SQLite's default behavior is to return a SQLITE_BUSY (i.e. database is locked) when a locked database is encountered - but using this setting the system can instead opt to wait and periodically retry for a limited amount of time.

In the linked PR I have made the busy timeout configurable, and set a default busy timeout of 5 seconds similar to the rusqlite driver as that seems like a reasonable default.

breckcs commented 3 months ago

@Mytherin, thank you for looking into this.

I updated my test project to include your fixes from #83, but, unfortunately, it doesn't fix the problem.

Tests 3, 4, and 5 (described above) still fail the same way, including the access to undefined memory crash in test 4.

Interestingly, test 6 now passes (using the DuckDB client to both read and write with WAL enabled). Perhaps this also suggest some binary incompatibility issues between duckdb-rs and rusqlite?

Mytherin commented 3 months ago

Apologies - you are correct. I had not run the original test suite with the new extension but instead ran with DuckDB running in a separate process from rusqlite, and that works as expected. The problem occurs specifically when running rusqlite and DuckDB with the sqlite extension in the same process.

I think your suspicion is correct and that there is something going wrong with conflicting versions of SQLite within the same process. When disabling the bundled setting of rusqlite I can no longer reproduce the issue and it seems to work correctly:

$ >  cargo test sqlite_writer_duckdb_reader_with_wal -- --nocapture

DuckDB COUNT : 9999
DuckDB COUNT : 10000
test tests::test_sqlite_writer_duckdb_reader_with_wal ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 5 filtered out; finished in 13.69s
diff --git a/Cargo.lock b/Cargo.lock
index b257ebb..5117edd 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -718,7 +718,6 @@ version = "0.28.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "0c10584274047cb335c23d3e61bcef8e323adae7c5c8c760540f73610177fc3f"
 dependencies = [
- "cc",
  "pkg-config",
  "vcpkg",
 ]
diff --git a/Cargo.toml b/Cargo.toml
index 7ee27d9..9ca16c0 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -4,5 +4,5 @@ version = "0.1.0"
 edition = "2021"

 [dependencies]
-rusqlite = { version = "0.31.0", features = ["bundled", "limits"] }
+rusqlite = { version = "0.31.0", features = ["limits"] }
 duckdb = { version = "0.10.1", features = ["bundled"]}
\ No newline at end of file

As to why that works - I could not figure out with complete certainty, but I do have a theory. The problem could be that both rusqlite and DuckDB's sqlite extension bundle their own version of SQLite. As a result, when running your test project, there are actually two versions of SQLite running concurrently within the same process - the version bundled by rusqlite, and the version bundled by the DuckDB SQLite extension. Due to the way that shared libraries work (at least on MacOS), these are isolated, and have their own version of all global/static variables.

SQLite's concurrency model works based on locks. In particular - it is not actually possible to safely/correctly read from a SQLite database file while it is being written to. SQLite resolves this using locks at two levels: file system level locks (using fcntl) and mutexes within the same process.

Now as to why this throws a bus error, I'm still a bit puzzled. Particularly because the bus error seems to happen in the writing thread (as you mentioned the bad access happens in walIndexAppend from rusqlite). I do have a suspicion there as well - DuckDB opens a separate transaction for each read. So what is actually happening for each read iteration within SQLite is:

BEGIN TRANSACTION;
SELECT COUNT(*) FROM users;
COMMIT;

Maybe beginning/commiting a transaction in WAL mode has some sort of effect on the WAL that causes the problem to happen there.

I've also succeeded in reproducing this in Python using the following script:

import duckdb
import sqlite3
import threading
import time
import os

sqlite_db = 'sqlite_writer_duckdb_reader_no_wal.db'
insert_count = 10000

def sqlite_write_thread():
    con = sqlite3.connect(sqlite_db)
    con.execute("PRAGMA journal_mode='WAL'")
    con.execute('CREATE TABLE IF NOT EXISTS users (name VARCHAR, age INTEGER);')
    for i in range(insert_count):
        time.sleep(0.001)
        con.execute("INSERT INTO users VALUES ('Alice', (?))", (i,))
        con.commit()
    res = con.execute('SELECT COUNT(*) FROM users').fetchall()
    if res[0][0] != insert_count:
        print(f"Failed to insert all rows - got {res[0][0]} rows instead of {insert_count}")
        exit(1)
    print('Finished inserting')

def duckdb_read_thread():
    con = duckdb.connect(config={'allow_unsigned_extensions': True})
    con.sql(f"ATTACH '{sqlite_db}' AS sqlite_db (TYPE SQLITE, READ_ONLY);")
    while True:
        time.sleep(0.01)
        res = con.sql('SELECT COUNT(*) FROM sqlite_db.users').fetchall()
        print(res[0][0])
        if res[0][0] == insert_count:
            break

try:
    os.remove(sqlite_db)
except:
    pass

write_thread = threading.Thread(target=sqlite_write_thread)
read_thread = threading.Thread(target=duckdb_read_thread)
write_thread.start()
time.sleep(1)
read_thread.start()
write_thread.join()
read_thread.join()

Which similarly results in either a bus error or a bad access, always in walIndexAppend in the writing thread.

I will investigate more - in particular I'm curious to see if I can trigger this using a C program that uses only sqlite API calls - but the more I'm looking into it the more this is looking like a problem in SQLite itself - and I'm not entirely sure if the solution actually has a fix other than making sure not to run multiple versions of SQLite in the same process.

Mytherin commented 3 months ago

Looking around more, and this actually seems to be a known issue in SQLite itself: https://www.sqlite.org/howtocorrupt.html#multiple_copies_of_sqlite_linked_into_the_same_application

Posix advisory locks canceled by a separate thread doing close()

The default locking mechanism used by SQLite on unix platforms is POSIX advisory locking. Unfortunately, POSIX advisory locking has design quirks that make it prone to misuse and failure. In particular, any thread in the same process with a file descriptor that is holding a POSIX advisory lock can override that lock using a different file descriptor. One particularly pernicious problem is that the close() system call will cancel all POSIX advisory locks on the same file for all threads and all file descriptors in the process.

So, for example, suppose a multi-thread process has two or more threads with separate SQLite database connections to the same database file. Then a third thread comes along and wants to read something out of that same database file on its own, without using the SQLite library. The third thread does an open(), a read() and then a close(). One would think this would be harmless. But the close() system call caused the locks held on the database by all the other threads to be dropped. Those other threads have no way of knowing that their locks have just been trashed (POSIX does not provide any mechanism to determine this) and so they keep on running under the assumption that their locks are still valid. This can lead to two or more threads or processes trying to write to the database at the same time, resulting in database corruption.

Note that it is perfectly safe for two or more threads to access the same SQLite database file using the SQLite library. The unix drivers for SQLite know about the POSIX advisory locking quirks and work around them. This problem only arises when a thread tries to bypass the SQLite library and read the database file directly.

Multiple copies of SQLite linked into the same application

As pointed out in the previous paragraph, SQLite takes steps to work around the quirks of POSIX advisory locking. Part of that work-around involves keeping a global list (mutex protected) of open SQLite database files. But, if multiple copies of SQLite are linked into the same application, then there will be multiple instances of this global list. Database connections opened using one copy of the SQLite library will be unaware of database connections opened using the other copy, and will be unable to work around the POSIX advisory locking quirks. A close() operation on one connection might unknowingly clear the locks on a different database connection, leading to database corruption.

The scenario above sounds far-fetched. But the SQLite developers are aware of at least one commercial product that was released with exactly this bug. The vendor came to the SQLite developers seeking help in tracking down some infrequent database corruption issues they were seeing on Linux and Mac. The problem was eventually traced to the fact that the application was linking against two separate copies of SQLite. The solution was to change the application build procedures to link against just one copy of SQLite instead of two.

Mytherin commented 3 months ago

Have found some other people encountering the same issue when using SQLite - https://github.com/tensorflow/tensorboard/issues/1467

This is a rather gnarly issue. The only way to nicely solve this is to stop bundling SQLite with the SQLite extension, and instead link to the same SQLite that is present for a given platform (e.g. link to libsqlite3-sys for Rust, the bundled sqlite library for Python, etc). But then not bundling SQLite means the extension is not usable unless the user manually links in SQLite which hurts usability in the general case. We also can't detect if another version of SQLite is present reliably, except unless maybe it has been loaded using RTLD_GLOBAL in which case we could check the global namespace for SQLite symbols.

In the RTLD_GLOBAL case we could do something clever where we could rename the symbols in our bundled version to something like bundled_sqlite3_open_v2, etc. Then we can first check if an existing SQLite installation is present by calling dlopen(nullptr) -> dlsym(main_lib, "sqlite3_open_v2"). Afterwards we could either use the already present global symbols, or fallback to our bundled implementation if none is present. That might solve the issue at least for platforms where the sqlite symbols are loaded in the global namespace.

breckcs commented 2 months ago

Removing the bundled setting of rusqlite makes the tests that write with SQLite and read with DuckDB pass (tests 3 and 4 described above): https://github.com/breckcs/duckdb_sqlite_scanner_concurrency_tests/pull/2.

The performance in WAL mode with a SQLite writer and a DuckDB reader seems the same as a SQLite writer and a SQLIte reader (comparing test 2 and 4), but without WAL mode, the DuckDB reader is significantly slower (comparing tests 1 and 3).

I opened a PR to update the DuckDB documentation with considerations for concurrency and included a warning about linking to two copies of the same SQLite library in the same process: https://github.com/duckdb/duckdb-web/pull/2742.

Interestingly, the last two tests that both read and write to SQLite using only DuckDB still don't work:

  1. test_duckdb_writer_duckdb_reader_no_wal fails with database is locked errors.
  2. test_duckdb_writer_duckdb_reader_with_wal passes, but runs very slowly and the counters do not update for long periods of time.