Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Random test suite crash #514

Open
lnicola opened this issue Jan 10, 2024 · 23 comments
Open

Random test suite crash #514

lnicola opened this issue Jan 10, 2024 · 23 comments

Comments

@lnicola
Copy link
Member

lnicola commented Jan 10, 2024

Just ran into this on #510 (but can't reproduce it easily):

Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmpgi6DfV.gpkg'
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
test spatial_ref::srs::tests::predicats_epsg2154 ... ok
test spatial_ref::srs::tests::get_units_epsg4326 ... ok
test spatial_ref::srs::tests::non_existing_proj_param ... ok
test vector::layer::tests::test_create_layer_options ... ok
error: test failed, to rerun pass `--lib`

Caused by:
  process didn't exit successfully: `/home/grayshade/Projects/georust/gdal/target/debug/deps/gdal-0978520db0adc3dd` (signal: 11, SIGSEGV: invalid memory reference)

That looks like a temporary file name, not sure what's going on.

@Atreyagaurav
Copy link
Contributor

Oh yeah, I ran into it once as well. It passed the next time I ran it, though. Maybe, like it said, the temp filename was coincidently the same as last time the test was done, and the file isn't cleared?

@lnicola
Copy link
Member Author

lnicola commented Jan 10, 2024

No, they're checked for collisions.

Not saying it's because of your changes, I just didn't see it before.

@metasim
Copy link
Contributor

metasim commented Jan 11, 2024

Been a while since I've seen this. I'd start with checking to ensure any test that mutates an on-disk fixture is using the TempFixture tooling, so as to work on separate copies of the file.

@lnicola
Copy link
Member Author

lnicola commented Jan 11, 2024

Hmm, I was able to reproduce the crash on master, so it's not #510. The "Layer new already exists" message points to the poly.gpkg tests, which we should fix.

However, running cargo test vector in a loop doesn't seem to crash, so it's still possible that the SIGSEGV is unrelated.

@lnicola
Copy link
Member Author

lnicola commented Jan 11, 2024

#0  0x00007ffff768dfcb in OGR2SQLITEModule::Setup(sqlite3*) () from /lib64/libgdal.so.33
#1  0x00007ffff768e7d5 in OGR2SQLITE_Setup(GDALDataset*, OGRSQLiteDataSource*) () from /lib64/libgdal.so.33
#2  0x00007ffff797d9fb in OGRSQLiteDataSource::OpenOrCreateDB(int, bool) [clone .constprop.0] () from /lib64/libgdal.so.33
#3  0x00007ffff7656825 in OGRSQLiteDataSource::Open(GDALOpenInfo*) () from /lib64/libgdal.so.33
#4  0x00007ffff7677bd4 in OGRSQLiteDriverOpen(GDALOpenInfo*) () from /lib64/libgdal.so.33
#5  0x00007ffff781a4e7 in GDALOpenEx () from /lib64/libgdal.so.33
#6  0x00007ffff73065e5 in RasterliteDataset::Open(GDALOpenInfo*) () from /lib64/libgdal.so.33
#7  0x00007ffff781a4e7 in GDALOpenEx () from /lib64/libgdal.so.33
#8  0x0000555555672295 in gdal::dataset::Dataset::_open_ex (path=..., options=...) at src/dataset.rs:148
#9  0x00005555556d8adb in gdal::dataset::Dataset::open<std::path::PathBuf> (path=...) at src/dataset.rs:61
#10 0x00005555556ef76e in gdal::vector::layer::tests::ds_with_layer<gdal::vector::layer::tests::test_field_in_layer::{closure_env#0}> (ds_name=..., layer_name=..., f=...) at src/vector/layer.rs:745
#11 0x00005555557010ee in gdal::vector::layer::tests::test_field_in_layer () at src/vector/layer.rs:1164
#12 0x00005555556f7b87 in gdal::vector::layer::tests::test_field_in_layer::{closure#0} () at src/vector/layer.rs:1163
#13 0x00005555556afe46 in core::ops::function::FnOnce::call_once<gdal::vector::layer::tests::test_field_in_layer::{closure_env#0}, ()> () at /rustc/0e09125c6c3c2fd70d7de961bcf0e51575235fad/library/core/src/ops/function.rs:250
#14 0x00005555557577df in core::ops::function::FnOnce::call_once<fn() -> core::result::Result<(), alloc::string::String>, ()> () at library/core/src/ops/function.rs:250
#15 test::__rust_begin_short_backtrace<core::result::Result<(), alloc::string::String>, fn() -> core::result::Result<(), alloc::string::String>> () at library/test/src/lib.rs:627
#16 0x0000555555756561 in test::run_test_in_process::{closure#0} () at library/test/src/lib.rs:650
#17 core::panic::unwind_safe::{impl#23}::call_once<core::result::Result<(), alloc::string::String>, test::run_test_in_process::{closure_env#0}> () at library/core/src/panic/unwind_safe.rs:272
#18 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panicking.rs:552
#19 std::panicking::try<core::result::Result<(), alloc::string::String>, core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>> () at library/std/src/panicking.rs:516
#20 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panic.rs:142
#21 test::run_test_in_process () at library/test/src/lib.rs:650
#22 test::run_test::{closure#0} () at library/test/src/lib.rs:573
#23 0x000055555571b416 in test::run_test::{closure#1} () at library/test/src/lib.rs:601
#24 std::sys_common::backtrace::__rust_begin_short_backtrace<test::run_test::{closure_env#1}, ()> () at library/std/src/sys_common/backtrace.rs:155
#25 0x0000555555720477 in std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure#0}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:529
#26 core::panic::unwind_safe::{impl#23}::call_once<(), std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>> () at library/core/src/panic/unwind_safe.rs:272
#27 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panicking.rs:552
#28 std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>> () at library/std/src/panicking.rs:516
#29 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panic.rs:142
#30 std::thread::{impl#0}::spawn_unchecked_::{closure#1}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:528
#31 core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked_::{closure_env#1}<test::run_test::{closure_env#1}, ()>, ()> () at library/core/src/ops/function.rs:250
#32 0x00005555557a3cf5 in alloc::boxed::{impl#47}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#33 alloc::boxed::{impl#47}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#34 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#35 0x00007ffff65cb897 in start_thread () from /lib64/libc.so.6
#36 0x00007ffff66526fc in clone3 () from /lib64/libc.so.6

Caught it with while gdb -ex=r -ex=quit --args target/debug/deps/gdal-0978520db0adc3dd; end.

@metasim
Copy link
Contributor

metasim commented Jan 11, 2024

Caught it with...

Great tip!

Am I right that both proj and gpkg use SQLite? If so, I wonder if there's any chance one of them was compiled with a different version than the other? 🤷 Shooting in the dark here.

@lnicola
Copy link
Member Author

lnicola commented Jan 11, 2024

They should be dynamically linked. I think SQLite is pretty robust, at least in some build configurations (unlike.. ahem.. netcdf).

And I couldn't trigger it when filtering by layers (or anything else), so it might be interference from am unrelated test. Maybe even from proj.

@lnicola
Copy link
Member Author

lnicola commented Jan 12, 2024

I still had gdb running, so I checked the other threads:

(gdb) info thread
  Id   Target Id                                            Frame 
  1    Thread 0x7ffff1b5cf40 (LWP 509695) "gdal-0978520db0" 0x00007ffff66526ed in clone3 () from /lib64/libc.so.6
  57   Thread 0x7ffeedd716c0 (LWP 509755) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  59   Thread 0x7ffeedf726c0 (LWP 509757) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  61   Thread 0x7ffeedb706c0 (LWP 509759) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  64   Thread 0x7ffee73f96c0 (LWP 509762) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  66   Thread 0x7ffee71f86c0 (LWP 509764) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  68   Thread 0x7ffeec9676c0 (LWP 509766) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  70   Thread 0x7ffeed56d6c0 (LWP 509768) "raster::process" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  79   Thread 0x7ffeecb686c0 (LWP 509777) "raster::tests::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  106  Thread 0x7ffeee1736c0 (LWP 509804) "raster::tests::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  130  Thread 0x7ffeed36c6c0 (LWP 509828) "spatial_ref::sr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  135  Thread 0x7ffee77fb6c0 (LWP 509833) "spatial_ref::sr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  141  Thread 0x7ffee6df66c0 (LWP 509839) "spatial_ref::sr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  143  Thread 0x7ffee75fa6c0 (LWP 509841) "spatial_ref::sr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  145  Thread 0x7ffee67f36c0 (LWP 509843) "spatial_ref::sr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  147  Thread 0x7ffeec3646c0 (LWP 509845) "spatial_ref::tr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  148  Thread 0x7ffeed96f6c0 (LWP 509846) "spatial_ref::tr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  149  Thread 0x7ffee7bfd6c0 (LWP 509847) "spatial_ref::tr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  150  Thread 0x7ffeee5756c0 (LWP 509848) "spatial_ref::tr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  151  Thread 0x7ffee79fc6c0 (LWP 509849) "spatial_ref::tr" 0x00007ffff515f8a0 in sqlite3WindowRewrite.lto_priv.0 () from /lib64/libsqlite3.so.0
  152  Thread 0x7ffeec5656c0 (LWP 509850) "spatial_ref::tr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  153  Thread 0x7ffeed76e6c0 (LWP 509851) "vector::feature" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  155  Thread 0x7ffeee7766c0 (LWP 509853) "vector::feature" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  167  Thread 0x7ffeee3746c0 (LWP 509865) "vector::geometr" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  169  Thread 0x7ffee6ff76c0 (LWP 509867) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  170  Thread 0x7ffeec7666c0 (LWP 509868) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  171  Thread 0x7ffee7dfe6c0 (LWP 509869) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  172  Thread 0x7ffee6bf56c0 (LWP 509870) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  173  Thread 0x7ffeecd696c0 (LWP 509871) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  174  Thread 0x7ffeecf6a6c0 (LWP 509872) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
* 175  Thread 0x7ffeed16b6c0 (LWP 509873) "vector::layer::" 0x00007ffff768dfcb in OGR2SQLITEModule::Setup(sqlite3*) () from /lib64/libgdal.so.33
  176  Thread 0x7ffee69f46c0 (LWP 509874) "vector::layer::" 0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
  177  Thread 0x7ffee7fff6c0 (LWP 509875) "gdal-0978520db0" 0x00007ffff66526ed in clone3 () from /lib64/libc.so.6

(gdb) t 151
[Switching to thread 151 (Thread 0x7ffee79fc6c0 (LWP 509849))]
#0  0x00007ffff515f8a0 in sqlite3WindowRewrite.lto_priv.0 () from /lib64/libsqlite3.so.0
(gdb) bt
#0  0x00007ffff515f8a0 in sqlite3WindowRewrite.lto_priv.0 () from /lib64/libsqlite3.so.0
#1  0x00007ffff5141a75 in sqlite3Select.lto_priv.0 () from /lib64/libsqlite3.so.0
#2  0x00007ffff51c7b98 in yy_reduce.isra () from /lib64/libsqlite3.so.0
#3  0x00007ffff5162d2d in sqlite3RunParser.lto_priv.0 () from /lib64/libsqlite3.so.0
#4  0x00007ffff5136845 in sqlite3Prepare () from /lib64/libsqlite3.so.0
#5  0x00007ffff51379f0 in sqlite3LockAndPrepare.lto_priv.0 () from /lib64/libsqlite3.so.0
#6  0x00007ffff5137b5e in sqlite3_prepare_v2 () from /lib64/libsqlite3.so.0
#7  0x00007ffff361798f in osgeo::proj::io::DatabaseContext::Private::run(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::list<osgeo::proj::io::SQLValues, std::allocator<osgeo::proj::io::SQLValues> > const&, bool) () from /lib64/libproj.so.25
#8  0x00007ffff362b250 in osgeo::proj::io::AuthorityFactory::Private::run(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::list<osgeo::proj::io::SQLValues, std::allocator<osgeo::proj::io::SQLValues> > const&) () from /lib64/libproj.so.25
#9  0x00007ffff3645e8d in osgeo::proj::io::AuthorityFactory::createFromCoordinateReferenceSystemCodes(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool, bool, bool, bool, bool, bool, std::shared_ptr<osgeo::proj::metadata::Extent> const&, std::shared_ptr<osgeo::proj::metadata::Extent> const&) const () from /lib64/libproj.so.25
#10 0x00007ffff368c3c1 in osgeo::proj::operation::CoordinateOperationFactory::Private::findOpsInRegistryDirect(dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, osgeo::proj::operation::CoordinateOperationFactory::Private::Context&, bool&) () from /lib64/libproj.so.25
#11 0x00007ffff36974ba in osgeo::proj::operation::CoordinateOperationFactory::Private::createOperationsFromDatabase(dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, osgeo::proj::operation::CoordinateOperationFactory::Private::Context&, osgeo::proj::crs::GeodeticCRS const*, osgeo::proj::crs::GeodeticCRS const*, osgeo::proj::crs::GeographicCRS const*, osgeo::proj::crs::GeographicCRS const*, osgeo::proj::crs::VerticalCRS const*, osgeo::proj::crs::VerticalCRS const*, std::vector<dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::operation::CoordinateOperation> >, std::allocator<dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::operation::CoordinateOperation> > > >&) () from /lib64/libproj.so.25
#12 0x00007ffff3699e71 in osgeo::proj::operation::CoordinateOperationFactory::Private::createOperations(dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, osgeo::proj::operation::CoordinateOperationFactory::Private::Context&) () from /lib64/libproj.so.25
#13 0x00007ffff36b1de6 in osgeo::proj::operation::CoordinateOperationFactory::createOperations(dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, dropbox::oxygen::nn<std::shared_ptr<osgeo::proj::crs::CRS> > const&, dropbox::oxygen::nn<std::unique_ptr<osgeo::proj::operation::CoordinateOperationContext, std::default_delete<osgeo::proj::operation::CoordinateOperationContext> > > const&) const () from /lib64/libproj.so.25
#14 0x00007ffff367ced7 in proj_create_operations () from /lib64/libproj.so.25
#15 0x00007ffff34d2f37 in proj_create_crs_to_crs_from_pj () from /lib64/libproj.so.25
#16 0x00007ffff6da4dcf in OGRCreateCoordinateTransformation(OGRSpatialReference const*, OGRSpatialReference const*, OGRCoordinateTransformationOptions const&) () from /lib64/libgdal.so.33
#17 0x00007ffff6da5f00 in OGRCreateCoordinateTransformation(OGRSpatialReference const*, OGRSpatialReference const*) () from /lib64/libgdal.so.33
#18 0x000055555566aae3 in gdal::spatial_ref::transform::CoordTransform::new (source=0x7ffee79f2bf8, target=0x7ffee79f2c48) at src/spatial_ref/transform.rs:29
#19 0x00005555556cb9dc in gdal::spatial_ref::transform_opts::tests::invalid_transformation () at src/spatial_ref/transform_opts.rs:170
#20 0x00005555556042c7 in gdal::spatial_ref::transform_opts::tests::invalid_transformation::{closure#0} () at src/spatial_ref/transform_opts.rs:165
#21 0x00005555556ad0a6 in core::ops::function::FnOnce::call_once<gdal::spatial_ref::transform_opts::tests::invalid_transformation::{closure_env#0}, ()> ()
    at /rustc/0e09125c6c3c2fd70d7de961bcf0e51575235fad/library/core/src/ops/function.rs:250
#22 0x00005555557577df in core::ops::function::FnOnce::call_once<fn() -> core::result::Result<(), alloc::string::String>, ()> () at library/core/src/ops/function.rs:250
#23 test::__rust_begin_short_backtrace<core::result::Result<(), alloc::string::String>, fn() -> core::result::Result<(), alloc::string::String>> () at library/test/src/lib.rs:627
#24 0x0000555555756561 in test::run_test_in_process::{closure#0} () at library/test/src/lib.rs:650
#25 core::panic::unwind_safe::{impl#23}::call_once<core::result::Result<(), alloc::string::String>, test::run_test_in_process::{closure_env#0}> () at library/core/src/panic/unwind_safe.rs:272
#26 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panicking.rs:552
#27 std::panicking::try<core::result::Result<(), alloc::string::String>, core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>> () at library/std/src/panicking.rs:516
#28 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panic.rs:142
#29 test::run_test_in_process () at library/test/src/lib.rs:650
#30 test::run_test::{closure#0} () at library/test/src/lib.rs:573
#31 0x000055555571b416 in test::run_test::{closure#1} () at library/test/src/lib.rs:601
#32 std::sys_common::backtrace::__rust_begin_short_backtrace<test::run_test::{closure_env#1}, ()> () at library/std/src/sys_common/backtrace.rs:155
#33 0x0000555555720477 in std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure#0}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:529
#34 core::panic::unwind_safe::{impl#23}::call_once<(), std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>> () at library/core/src/panic/unwind_safe.rs:272
#35 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panicking.rs:552
#36 std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>> () at library/std/src/panicking.rs:516
#37 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panic.rs:142
#38 std::thread::{impl#0}::spawn_unchecked_::{closure#1}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:528
#39 core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked_::{closure_env#1}<test::run_test::{closure_env#1}, ()>, ()> () at library/core/src/ops/function.rs:250
#40 0x00005555557a3cf5 in alloc::boxed::{impl#47}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#41 alloc::boxed::{impl#47}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#42 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#43 0x00007ffff65cb897 in start_thread () from /lib64/libc.so.6
#44 0x00007ffff66526fc in clone3 () from /lib64/libc.so.6

(gdb) t 68
[Switching to thread 68 (Thread 0x7ffeec9676c0 (LWP 509766))]
#0  0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
(gdb) bt
#0  0x00007ffff65c83c0 in __lll_lock_wait () from /lib64/libc.so.6
#1  0x00007ffff65cee97 in pthread_mutex_lock@@GLIBC_2.2.5 () from /lib64/libc.so.6
#2  0x00007ffff50efa4e in columnMem () from /lib64/libsqlite3.so.0
#3  0x00007ffff50efd23 in sqlite3_column_text () from /lib64/libsqlite3.so.0
#4  0x00007ffff3614cdb in osgeo::proj::io::SQLiteHandle::run(sqlite3_stmt*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::list<osgeo::proj::io::SQLValues, std::allocator<osgeo::proj::io::SQLValues> > const&, bool) () from /lib64/libproj.so.25
#5  0x00007ffff3617927 in osgeo::proj::io::DatabaseContext::Private::run(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::list<osgeo::proj::io::SQLValues, std::allocator<osgeo::proj::io::SQLValues> > const&, bool) () from /lib64/libproj.so.25
#6  0x00007ffff362b250 in osgeo::proj::io::AuthorityFactory::Private::run(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::list<osgeo::proj::io::SQLValues, std::allocator<osgeo::proj::io::SQLValues> > const&) () from /lib64/libproj.so.25
#7  0x00007ffff365428b in osgeo::proj::io::AuthorityFactory::createObjectsFromNameEx(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<osgeo::proj::io::AuthorityFactory::ObjectType, std::allocator<osgeo::proj::io::AuthorityFactory::ObjectType> > const&, bool, unsigned long) const () from /lib64/libproj.so.25
#8  0x00007ffff3655087 in osgeo::proj::io::AuthorityFactory::createObjectsFromName(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::vector<osgeo::proj::io::AuthorityFactory::ObjectType, std::allocator<osgeo::proj::io::AuthorityFactory::ObjectType> > const&, bool, unsigned long) const () from /lib64/libproj.so.25
#9  0x00007ffff35af966 in osgeo::proj::datum::GeodeticReferenceFrame::_exportToWKT(osgeo::proj::io::WKTFormatter*) const () from /lib64/libproj.so.25
#10 0x00007ffff358173a in osgeo::proj::crs::GeodeticCRS::_exportToWKT(osgeo::proj::io::WKTFormatter*) const () from /lib64/libproj.so.25
#11 0x00007ffff35c0533 in osgeo::proj::io::IWKTExportable::exportToWKT[abi:cxx11](osgeo::proj::io::WKTFormatter*) const () from /lib64/libproj.so.25
#12 0x00007ffff3661ed6 in proj_as_wkt () from /lib64/libproj.so.25
#13 0x00007ffff6d8ad03 in OGRSpatialReference::exportToWkt(char**, char const* const*) const () from /lib64/libgdal.so.33
#14 0x00007ffff780fb0d in GDALDataset::GetProjectionRef() const () from /lib64/libgdal.so.33
#15 0x00007ffff792f474 in GDALDEMProcessing () from /lib64/libgdal.so.33
#16 0x00005555556de2d6 in gdal::raster::processing::dem::dem_eval (src=0x7ffeec95c8d8, dst_file=..., alg=gdal::raster::processing::dem::options::DemAlg::Tpi, options=0x7ffeec95c558, color_relief_config=...)
    at src/raster/processing/dem/mod.rs:460
#17 0x000055555563e1e2 in gdal::raster::processing::dem::topographic_position_index<&std::path::Path> (ds=0x7ffeec95c8d8, dest_file=..., options=0x7ffeec95c8a8) at src/raster/processing/dem/mod.rs:384
#18 0x00005555556497dc in gdal::raster::processing::dem::tpi::tests::test_tpi () at src/raster/processing/dem/tpi.rs:63
#19 0x00005555557177ed in gdal::raster::processing::dem::tpi::tests::test_tpi::{closure#0} () at src/raster/processing/dem/tpi.rs:57
#20 0x00005555556b0096 in core::ops::function::FnOnce::call_once<gdal::raster::processing::dem::tpi::tests::test_tpi::{closure_env#0}, ()> () at /rustc/0e09125c6c3c2fd70d7de961bcf0e51575235fad/library/core/src/ops/function.rs:250
#21 0x00005555557577df in core::ops::function::FnOnce::call_once<fn() -> core::result::Result<(), alloc::string::String>, ()> () at library/core/src/ops/function.rs:250
#22 test::__rust_begin_short_backtrace<core::result::Result<(), alloc::string::String>, fn() -> core::result::Result<(), alloc::string::String>> () at library/test/src/lib.rs:627
#23 0x0000555555756561 in test::run_test_in_process::{closure#0} () at library/test/src/lib.rs:650
#24 core::panic::unwind_safe::{impl#23}::call_once<core::result::Result<(), alloc::string::String>, test::run_test_in_process::{closure_env#0}> () at library/core/src/panic/unwind_safe.rs:272
#25 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panicking.rs:552
#26 std::panicking::try<core::result::Result<(), alloc::string::String>, core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>> () at library/std/src/panicking.rs:516
#27 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panic.rs:142
#28 test::run_test_in_process () at library/test/src/lib.rs:650
#29 test::run_test::{closure#0} () at library/test/src/lib.rs:573
#30 0x000055555571b416 in test::run_test::{closure#1} () at library/test/src/lib.rs:601
#31 std::sys_common::backtrace::__rust_begin_short_backtrace<test::run_test::{closure_env#1}, ()> () at library/std/src/sys_common/backtrace.rs:155
#32 0x0000555555720477 in std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure#0}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:529
#33 core::panic::unwind_safe::{impl#23}::call_once<(), std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>> () at library/core/src/panic/unwind_safe.rs:272
#34 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panicking.rs:552
#35 std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>> () at library/std/src/panicking.rs:516
#36 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panic.rs:142
#37 std::thread::{impl#0}::spawn_unchecked_::{closure#1}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:528
#38 core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked_::{closure_env#1}<test::run_test::{closure_env#1}, ()>, ()> () at library/core/src/ops/function.rs:250
#39 0x00005555557a3cf5 in alloc::boxed::{impl#47}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#40 alloc::boxed::{impl#47}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#41 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#42 0x00007ffff65cb897 in start_thread () from /lib64/libc.so.6
#43 0x00007ffff66526fc in clone3 () from /lib64/libc.so.6

So indeed, it looks like proj is also calling into SQLite at the same time, not that it proves anything.

EDIT: another one, this time with debug symbols:

Thread 175 "vector::layer::" received signal SIGSEGV, Segmentation fault.
0x00007ffff768dfcb in OGR2SQLITEModule::Setup (this=this@entry=0x7ffe74007820, hDBIn=0x7ffe74019aa0) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp:2611
2611        int rc = sqlite3_create_module_v2(hDB, "VirtualOGR", &sOGR2SQLITEModule,                                                                                                                                                          

(gdb) bt
#0  0x00007ffff768dfcb in OGR2SQLITEModule::Setup (this=this@entry=0x7ffe74007820, hDBIn=0x7ffe74019aa0) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp:2611
#1  0x00007ffff768e7d5 in OGR2SQLITEModule::Setup (poSQLiteDSIn=0x7ffe7402b530, poDSIn=0x7ffe7402b530, this=0x7ffe74007820) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitebase.h:176
#2  OGR2SQLITE_Setup (poDS=0x7ffe7402b530, poSQLiteDS=0x7ffe7402b530) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp:2658
#3  0x00007ffff797d9fb in OGRSQLiteDataSource::OpenOrCreateDB(int, bool) [clone .constprop.0] (this=0x7ffe7402b530, flagsIn=<optimized out>, bRegisterOGR2SQLiteExtensions=true)
    at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitedatasource.cpp:1668
#4  0x00007ffff7656825 in OGRSQLiteDataSource::Open (this=0x7ffe7402b530, poOpenInfo=0x7ffeec55b0e0) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitedatasource.cpp:2355
#5  0x00007ffff7677bd4 in OGRSQLiteDriverOpen (poOpenInfo=0x7ffeec55b0e0) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitedriver.cpp:211
#6  0x00007ffff781a4e7 in GDALOpenEx (pszFilename=0x7ffe7401d2e0 "/home/grayshade/Projects/georust/gdal/fixtures/three_layer_ds.s3db", nOpenFlags=4, papszAllowedDrivers=0x7ffeec55b390, papszOpenOptions=0x0, 
    papszSiblingFiles=<optimized out>) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/gcore/gdaldataset.cpp:3550
#7  0x00007ffff73065e5 in RasterliteOpenSQLiteDB (eAccess=<optimized out>, pszFilename=<optimized out>) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/frmts/rasterlite/rasterlitedataset.cpp:55
#8  RasterliteDataset::Open (poOpenInfo=0x7ffeec55b540) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/frmts/rasterlite/rasterlitedataset.cpp:1122
#9  0x00007ffff781a4e7 in GDALOpenEx (pszFilename=0x7ffe74019850 "/home/grayshade/Projects/georust/gdal/fixtures/three_layer_ds.s3db", nOpenFlags=14, papszAllowedDrivers=0x0, papszOpenOptions=0x0, papszSiblingFiles=<optimized out>)
    at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/gcore/gdaldataset.cpp:3550
#10 0x0000555555672295 in gdal::dataset::Dataset::_open_ex (path=..., options=...) at src/dataset.rs:148
#11 0x00005555556d8adb in gdal::dataset::Dataset::open<std::path::PathBuf> (path=...) at src/dataset.rs:61
#12 0x00005555556ef76e in gdal::vector::layer::tests::ds_with_layer<gdal::vector::layer::tests::test_field_in_layer::{closure_env#0}> (ds_name=..., layer_name=..., f=...) at src/vector/layer.rs:745
#13 0x00005555557010ee in gdal::vector::layer::tests::test_field_in_layer () at src/vector/layer.rs:1164
#14 0x00005555556f7b87 in gdal::vector::layer::tests::test_field_in_layer::{closure#0} () at src/vector/layer.rs:1163
#15 0x00005555556afe46 in core::ops::function::FnOnce::call_once<gdal::vector::layer::tests::test_field_in_layer::{closure_env#0}, ()> () at /rustc/0e09125c6c3c2fd70d7de961bcf0e51575235fad/library/core/src/ops/function.rs:250
#16 0x00005555557577df in core::ops::function::FnOnce::call_once<fn() -> core::result::Result<(), alloc::string::String>, ()> () at library/core/src/ops/function.rs:250
#17 test::__rust_begin_short_backtrace<core::result::Result<(), alloc::string::String>, fn() -> core::result::Result<(), alloc::string::String>> () at library/test/src/lib.rs:627
#18 0x0000555555756561 in test::run_test_in_process::{closure#0} () at library/test/src/lib.rs:650
#19 core::panic::unwind_safe::{impl#23}::call_once<core::result::Result<(), alloc::string::String>, test::run_test_in_process::{closure_env#0}> () at library/core/src/panic/unwind_safe.rs:272
#20 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panicking.rs:552
#21 std::panicking::try<core::result::Result<(), alloc::string::String>, core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>> () at library/std/src/panicking.rs:516
#22 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<test::run_test_in_process::{closure_env#0}>, core::result::Result<(), alloc::string::String>> () at library/std/src/panic.rs:142
#23 test::run_test_in_process () at library/test/src/lib.rs:650
#24 test::run_test::{closure#0} () at library/test/src/lib.rs:573
#25 0x000055555571b416 in test::run_test::{closure#1} () at library/test/src/lib.rs:601
#26 std::sys_common::backtrace::__rust_begin_short_backtrace<test::run_test::{closure_env#1}, ()> () at library/std/src/sys_common/backtrace.rs:155
#27 0x0000555555720477 in std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure#0}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:529
#28 core::panic::unwind_safe::{impl#23}::call_once<(), std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>> () at library/core/src/panic/unwind_safe.rs:272
#29 std::panicking::try::do_call<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panicking.rs:552
#30 std::panicking::try<(), core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>> () at library/std/src/panicking.rs:516
#31 std::panic::catch_unwind<core::panic::unwind_safe::AssertUnwindSafe<std::thread::{impl#0}::spawn_unchecked_::{closure#1}::{closure_env#0}<test::run_test::{closure_env#1}, ()>>, ()> () at library/std/src/panic.rs:142
#32 std::thread::{impl#0}::spawn_unchecked_::{closure#1}<test::run_test::{closure_env#1}, ()> () at library/std/src/thread/mod.rs:528
#33 core::ops::function::FnOnce::call_once<std::thread::{impl#0}::spawn_unchecked_::{closure_env#1}<test::run_test::{closure_env#1}, ()>, ()> () at library/core/src/ops/function.rs:250
#34 0x00005555557a3cf5 in alloc::boxed::{impl#47}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#35 alloc::boxed::{impl#47}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:2015
#36 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#37 0x00007ffff65cb897 in start_thread (arg=<optimized out>) at pthread_create.c:444
#38 0x00007ffff66526fc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

(gdb) info threads
  Id   Target Id                                            Frame 
  1    Thread 0x7ffff1b5cf40 (LWP 688176) "gdal-0978520db0" clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:62
* 175  Thread 0x7ffeec5656c0 (LWP 688383) "vector::layer::" 0x00007ffff768dfcb in OGR2SQLITEModule::Setup (this=this@entry=0x7ffe74007820, hDBIn=0x7ffe74019aa0)
    at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp:2611
  177  Thread 0x7ffeec9676c0 (LWP 688385) "gdal-0978520db0" clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:62

The crash is at:

Dump of assembler code for function _ZN16OGR2SQLITEModule5SetupEP7sqlite3:
Address range 0x7ffff768df80 to 0x7ffff768e74c:
   0x00007ffff768df80 <+0>:	push   %rbp
   0x00007ffff768df81 <+1>:	lea    -0x188(%rip),%r8        # 0x7ffff768de00 <OGR2SQLITEDestroyModule(void*)>
   0x00007ffff768df88 <+8>:	lea    0x7ef1b1(%rip),%rdx        # 0x7ffff7e7d140 <_ZL17sOGR2SQLITEModule>
   0x00007ffff768df8f <+15>:	mov    %rsp,%rbp
   0x00007ffff768df92 <+18>:	push   %r15
   0x00007ffff768df94 <+20>:	push   %r14
   0x00007ffff768df96 <+22>:	push   %r13
   0x00007ffff768df98 <+24>:	push   %r12
   0x00007ffff768df9a <+26>:	push   %rbx
   0x00007ffff768df9b <+27>:	mov    %rdi,%rbx
   0x00007ffff768df9e <+30>:	mov    %rsi,%rdi
   0x00007ffff768dfa1 <+33>:	mov    %rbx,%rcx
   0x00007ffff768dfa4 <+36>:	sub    $0x88,%rsp
   0x00007ffff768dfab <+43>:	mov    %fs:0x28,%rax
   0x00007ffff768dfb4 <+52>:	mov    %rax,-0x38(%rbp)
   0x00007ffff768dfb8 <+56>:	xor    %eax,%eax
   0x00007ffff768dfba <+58>:	mov    0x8b162f(%rip),%rax        # 0x7ffff7f3f5f0 <_ZL11sqlite3_api.lto_priv.0>
   0x00007ffff768dfc1 <+65>:	mov    %rsi,(%rbx)
   0x00007ffff768dfc4 <+68>:	lea    0x56194a(%rip),%rsi        # 0x7ffff7bef915
=> 0x00007ffff768dfcb <+75>:	call   *0x3b8(%rax)
   0x00007ffff768dfd1 <+81>:	test   %eax,%eax
   0x00007ffff768dfd3 <+83>:	jne    0x7ffff768e4d0 <_ZN16OGR2SQLITEModule5SetupEP7sqlite3+1360>
   0x00007ffff768dfd9 <+89>:	mov    (%rbx),%rdi
   0x00007ffff768dfdc <+92>:	push   $0x0
   0x00007ffff768dfde <+94>:	lea    -0x455(%rip),%r9        # 0x7ffff768db90 <OGR2SQLITE_ogr_layer_Extent(sqlite3_context*, int, sqlite3_value**)>
   0x00007ffff768dfe5 <+101>:	mov    %rbx,%r8
   0x00007ffff768dfe8 <+104>:	push   $0x0
   0x00007ffff768dfea <+106>:	mov    0x8b15ff(%rip),%rax        # 0x7ffff7f3f5f0 <_ZL11sqlite3_api.lto_priv.0>
   0x00007ffff768dff1 <+113>:	mov    $0x5,%ecx
   0x00007ffff768dff6 <+118>:	mov    $0x1,%edx
   0x00007ffff768dffb <+123>:	lea    0x56e4f4(%rip),%rsi        # 0x7ffff7bfc4f6
   0x00007ffff768e002 <+130>:	call   *0x168(%rax)
   0x00007ffff768e008 <+136>:	pop    %r11
   0x00007ffff768e00a <+138>:	pop    %r12
   0x00007ffff768e00c <+140>:	test   %eax,%eax
   0x00007ffff768e00e <+142>:	jne    0x7ffff768e4d0 <_ZN16OGR2SQLITEModule5SetupEP7sqlite3+1360>
   0x00007ffff768e014 <+148>:	mov    (%rbx),%rdi
   0x00007ffff768e017 <+151>:	push   $0x0
   0x00007ffff768e019 <+153>:	lea    -0xcc0(%rip),%r9        # 0x7ffff768d360 <OGR2SQLITE_ogr_layer_SRID(sqlite3_context*, int, sqlite3_value**)>
   0x00007ffff768e020 <+160>:	mov    %rbx,%r8
   0x00007ffff768e023 <+163>:	push   $0x0
   0x00007ffff768e025 <+165>:	mov    0x8b15c4(%rip),%rax        # 0x7ffff7f3f5f0 <_ZL11sqlite3_api.lto_priv.0>
   0x00007ffff768e02c <+172>:	mov    $0x5,%ecx
   0x00007ffff768e031 <+177>:	mov    $0x1,%edx
   0x00007ffff768e036 <+182>:	lea    0x56e493(%rip),%rsi        # 0x7ffff7bfc4d0
   0x00007ffff768e03d <+189>:	call   *0x168(%rax)
   0x00007ffff768e043 <+195>:	pop    %r9
   0x00007ffff768e045 <+197>:	pop    %r10
   0x00007ffff768e047 <+199>:	test   %eax,%eax

So https://github.com/OSGeo/gdal/blob/6133cf34a78077998406c0c4045bf51f06e3f49d/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp#L2611 looks just about right.

(gdb) p *this
$9 = {hDB = 0x7ffe74019aa0, poDS = 0x7ffe7402b530, apoExtraDS = std::vector of length 0, capacity 0, poSQLiteDS = 0x7ffe7402b530, oMapVTableToOGRLayer = std::map with 0 elements, hHandleSQLFunctions = 0x0}

(gdb) p *hDB
$10 = {pVfs = 0x7ffff51fc200 <aVfs.105>, pVdbe = 0x0, pDfltColl = 0x7ffe74019de0, mutex = 0x0, aDb = 0x7ffe74019d38, nDb = 2, mDbFlags = 80, flags = 3758391520, lastRowid = 0, szMmap = 0, nSchemaLock = 0, openFlags = 1, errCode = 0, 
  errByteOffset = -1, errMask = 255, iSysErrno = 0, dbOptFlags = 0, enc = 1 '\001', autoCommit = 1 '\001', temp_store = 0 '\000', mallocFailed = 0 '\000', bBenignMalloc = 0 '\000', dfltLockMode = 0 '\000', nextAutovac = -1 '\377', 
  suppressErr = 0 '\000', vtabOnConflict = 0 '\000', isTransactionSavepoint = 0 '\000', mTrace = 0 '\000', noSharedCache = 1 '\001', nSqlExec = 0 '\000', eOpenState = 118 'v', nextPagesize = 0, nChange = 0, nTotalChange = 0, aLimit = {
    1000000000, 1000000000, 2000, 1000, 500, 250000000, 127, 10, 50000, 32766, 1000, 0}, nMaxSorterMmap = 0, init = {newTnum = 1, iDb = 0 '\000', busy = 0 '\000', orphanTrigger = 0, imposterTable = 0, reopenMemdb = 0, 
    azInit = 0x7ffff51fc860 <sqlite3StdType.lto_priv.0>}, nVdbeActive = 0, nVdbeRead = 0, nVdbeWrite = 0, nVdbeExec = 0, nVDestroy = 0, nExtension = 0, aExtension = 0x0, trace = {xLegacy = 0x0, xV2 = 0x0}, pTraceArg = 0x0, 
  xProfile = 0x0, pProfileArg = 0x0, pCommitArg = 0x0, xCommitCallback = 0x0, pRollbackArg = 0x0, xRollbackCallback = 0x0, pUpdateArg = 0x0, xUpdateCallback = 0x0, pAutovacPagesArg = 0x0, xAutovacDestr = 0x0, xAutovacPages = 0x0, 
  pParse = 0x0, xWalCallback = 0x7ffff5168e20 <sqlite3WalDefaultHook>, pWalArg = 0x3e8, xCollNeeded = 0x0, xCollNeeded16 = 0x0, pCollNeededArg = 0x0, pErr = 0x0, u1 = {isInterrupted = 0, notUsed1 = 0}, lookaside = {bDisable = 0, 
    sz = 1200, szTrue = 1200, bMalloced = 1 '\001', nSlot = 123, anStat = {134, 1, 0}, pInit = 0x7ffe74035be0, pFree = 0x7ffe74038160, pSmallInit = 0x7ffe74038c10, pSmallFree = 0x7ffe74038f90, pMiddle = 0x7ffe74038610, 
    pStart = 0x7ffe7402f970, pEnd = 0x7ffe7403b490, pTrueEnd = 0x7ffe7403b490}, xAuth = 0x0, pAuthArg = 0x0, xProgress = 0x0, pProgressArg = 0x0, nProgressOps = 0, nVTrans = 0, aModule = {htsize = 21, count = 12, first = 0x7ffe740072d0, 
    ht = 0x7ffe74009560}, pVtabCtx = 0x0, aVTrans = 0x0, pDisconnect = 0x0, aFunc = {htsize = 20, count = 13, first = 0x7ffe74006f50, ht = 0x7ffe74019f90}, aCollSeq = {htsize = 0, count = 3, first = 0x7ffe7401cef0, ht = 0x0}, 
  busyHandler = {xBusyHandler = 0x7ffff51635e0 <sqliteDefaultBusyCallback>, pBusyArg = 0x7ffe74019aa0, nBusy = 0}, aDbStatic = {{zDbSName = 0x7ffff51ce65d "main", pBt = 0x7ffe7400f710, safety_level = 3 '\003', bSyncSet = 0 '\000', 
      pSchema = 0x7ffe7401cfd0}, {zDbSName = 0x7ffff51d2cf1 "temp", pBt = 0x0, safety_level = 1 '\001', bSyncSet = 0 '\000', pSchema = 0x7ffe7400d970}}, pSavepoint = 0x0, nAnalysisLimit = 0, busyTimeout = 5000, nSavepoint = 0, 
  nStatement = 0, nDeferredCons = 0, nDeferredImmCons = 0, pnBytesFreed = 0x0, pBlockingConnection = 0x0, pUnlockConnection = 0x0, pUnlockArg = 0x0, xUnlockNotify = 0x0, pNextBlocked = 0x0}

(gdb) p *poDS
$11 = {<GDALMajorObject> = {_vptr.GDALMajorObject = 0x7ffff7edd5c0 <vtable for OGRSQLiteDataSource+16>, nFlags = 33, 
    sDescription = {<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >> = "/home/grayshade/Projects/georust/gdal/fixtures/three_layer_ds.s3db", <No data fields>}, oMDMD = {papszDomainList = 0x0, 
      papoMetadataLists = 0x0}}, poDriver = 0x0, eAccess = GA_ReadOnly, nRasterXSize = 512, nRasterYSize = 512, nBands = 0, papoBands = 0x0, static OPEN_FLAGS_CLOSED = -1, nOpenFlags = 4, nRefCount = 1, bForceCachedIO = false, 
  bShared = false, bIsInternal = true, bSuppressOnClose = false, m_oMapFieldDomains = std::map with 0 elements, oOvManager = {poDS = 0x0, poODS = 0x0, 
    osOvrFilename = {<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >> = "", <No data fields>}, bOvrIsAux = false, bCheckedForMask = false, bOwnMaskDS = false, poMaskDS = 0x0, poBaseDS = 0x0, 
    bCheckedForOverviews = false, pszInitName = 0x0, bInitNameIsOVR = false, papszInitSiblingFiles = 0x0}, papszOpenOptions = 0x0, m_poPrivate = 0x7ffe7400d010, oDerivedMetadataList = {papszList = 0x0, nCount = 0, nAllocation = 0, 
    bOwnList = false, bIsSorted = false}, m_poStyleTable = 0x0}

However, %rax is 0:

(gdb) info reg
rax            0x0                 0
rbx            0x7ffe74007820      140730844608544
rcx            0x7ffe74007820      140730844608544
rdx            0x7ffff7e7d140      140737352552768
rsi            0x7ffff7bef915      140737349875989
rdi            0x7ffe74019aa0      140730844682912
rbp            0x7ffeec55ad00      0x7ffeec55ad00
rsp            0x7ffeec55ac50      0x7ffeec55ac50
r8             0x7ffff768de00      140737344232960
r9             0x7ffe74000090      140730844577936
r10            0x90                144
r11            0x0                 0
r12            0x7ffe7402b530      140730844755248
r13            0x7ffe7402b530      140730844755248
r14            0x7ffff7bfc66b      140737349928555
r15            0x7ffeec55b160      140732863459680
rip            0x7ffff768dfcb      0x7ffff768dfcb <OGR2SQLITEModule::Setup(sqlite3*)+75>
eflags         0x10246             [ PF ZF IF RF ]
cs             0x33                51
ss             0x2b                43
ds             0x0                 0
es             0x0                 0
fs             0x0                 0
gs             0x0                 0
fs_base        0x7ffeec5656c0      140732863502016
gs_base        0x0                 0

So it looks like the sqlite3_create_module_v2 call is pointing nowhere, but I don't understand why.

@lnicola
Copy link
Member Author

lnicola commented Jan 12, 2024

CC @rouault I don't know if I can reproduce this in pure GDAL. It might be a race on our side between GDALAllRegister and e.g. OSRImportFromEPSG. Or maybe there's something fishy going on around OGR2SQLITE_Register.


I managed to reproduce this using 3 tests:

Crashed "target/release/deps/gdal-a5f1a0f14e3eca4c" "-q" "--test-threads" "2" "vector::layer::tests::test_field_in_layer" "vector::layer::tests::test_create_layer_options" "spatial_ref::transform_opts::tests::set_coordinate_operation": ExitStatus(unix_wait_status(139))

Anyway, taking a closer look at the assembly, _ZL11sqlite3_api.lto_priv.0 is NULL. That's a LTO-mangled name for sqlite3_api, from https://github.com/OSGeo/gdal/blob/6133cf34a78077998406c0c4045bf51f06e3f49d/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp#L135.

That seems to be initialized through OGR2SQLITE_Register (weird cast there) at https://github.com/OSGeo/gdal/blob/6133cf34a78077998406c0c4045bf51f06e3f49d/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp#L2760C5-L2760C27 (the macro expands to sqlite3_api = pApi).

But the stack trace has:

#0  0x00007ffff768dfcb in OGR2SQLITEModule::Setup (this=this@entry=0x7ffee0058a10, hDBIn=0x7ffee007cd50) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp:2611
#1  0x00007ffff768e7d5 in OGR2SQLITEModule::Setup (poSQLiteDSIn=0x7ffee002df40, poDSIn=0x7ffee002df40, this=0x7ffee0058a10) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitebase.h:176
#2  OGR2SQLITE_Setup (poDS=0x7ffee002df40, poSQLiteDS=0x7ffee002df40) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp:2658
#3  0x00007ffff797d9fb in OGRSQLiteDataSource::OpenOrCreateDB(int, bool) [clone .constprop.0] (this=0x7ffee002df40, flagsIn=<optimized out>, bRegisterOGR2SQLiteExtensions=true)
    at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitedatasource.cpp:1668
#4  0x00007ffff7656825 in OGRSQLiteDataSource::Open (this=0x7ffee002df40, poOpenInfo=0x7ffeee54d650) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitedatasource.cpp:2355
#5  0x00007ffff7677bd4 in OGRSQLiteDriverOpen (poOpenInfo=0x7ffeee54d650) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/ogr/ogrsf_frmts/sqlite/ogrsqlitedriver.cpp:211
#6  0x00007ffff781a4e7 in GDALOpenEx (pszFilename=0x7ffee008a3a0 "/home/grayshade/Projects/georust/gdal/fixtures/three_layer_ds.s3db", nOpenFlags=4, papszAllowedDrivers=0x7ffeee54d900, papszOpenOptions=0x0, 
    papszSiblingFiles=<optimized out>) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/gcore/gdaldataset.cpp:3550
#7  0x00007ffff73065e5 in RasterliteOpenSQLiteDB (eAccess=<optimized out>, pszFilename=<optimized out>) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/frmts/rasterlite/rasterlitedataset.cpp:55
#8  RasterliteDataset::Open (poOpenInfo=0x7ffeee54dab0) at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/frmts/rasterlite/rasterlitedataset.cpp:1122
#9  0x00007ffff781a4e7 in GDALOpenEx (pszFilename=0x7ffee0056c50 "/home/grayshade/Projects/georust/gdal/fixtures/three_layer_ds.s3db", nOpenFlags=14, papszAllowedDrivers=0x0, papszOpenOptions=0x0, papszSiblingFiles=<optimized out>)
    at /usr/src/debug/gdal-3.7.3-2.fc39.x86_64/gcore/gdaldataset.cpp:3550

So OGRSQLiteDataSource::OpenOrCreateDB(..., true) should have already called OGRSQLiteBaseDataSource::OpenOrCreateDB and OGR2SQLITE_Register, ending up at https://github.com/OSGeo/gdal/blob/6133cf34a78077998406c0c4045bf51f06e3f49d/ogr/ogrsf_frmts/sqlite/ogrsqlitedatasource.cpp#L1294. This is all on the same thread.

I don't really understand how this is happening, but it's probably caused by that sqlite3_api global.

@metasim
Copy link
Contributor

metasim commented Jan 12, 2024

Wow, nice work, and nice case study in using gdb with mixed language debugging! Thanks for sharing your process!

@lnicola
Copy link
Member Author

lnicola commented Jan 12, 2024

https://sqlite.org/src/file?name=src/sqlite3ext.h

#define sqlite3_create_module_v2       sqlite3_api->create_module_v2

Right, well that explains the indirect call in the asm 🤦‍♂️.

@rouault
Copy link
Contributor

rouault commented Jan 12, 2024

@lnicola I've tried to reproduce on my system using GDAL master and SQLite 3.31.4 (ubuntu 20.04), but target/release/deps/gdal-fcd32cea6720c7b7 "-q" "--test-threads" "2" "vector::layer::tests::test_field_in_layer" "vector::layer::tests::test_create_layer_options" "spatial_ref::transform_opts::tests::set_coordinate_operation" runs fine for me.

What could help perhaps is if you could add the following debug trace to your GDAL build:

--- a/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp
+++ b/ogr/ogrsf_frmts/sqlite/ogrsqlitevirtualogr.cpp
@@ -2827,6 +2827,10 @@ extern const struct sqlite3_api_routines OGRSQLITE_static_routines;
 int OGR2SQLITE_static_register(sqlite3 *hDB, char **pzErrMsg, void *_pApi)
 {
     const sqlite3_api_routines *pApi = (const sqlite3_api_routines *)_pApi;
+    fprintf(stderr, "pApi=%p, pApi->create_module = %p, pApi->create_module_v2 = %p\n",
+            pApi,
+            pApi ? pApi->create_module : nullptr,
+            pApi ? pApi->create_module_v2 : nullptr);
 #ifndef _WIN32
     if ((pApi == nullptr) || (pApi->create_module == nullptr))
     {

@lnicola
Copy link
Member Author

lnicola commented Jan 12, 2024

Will try, I have to build it first.

It's not too easy to reproduce, I was continuously running that in a loop, over 10 to 20 instances, and it still took a couple of minutes.

In any case, in my crash it's sqlite3_api that's null, not the create_module_v2 pointer.

@rouault
Copy link
Contributor

rouault commented Jan 12, 2024

in my crash it's sqlite3_api that's null,

Extermely weird. I don't see how that happen. Even if OGR2SQLITE_static_register() was called with _pApi == nullptr (which can only happen if SQLite is built with SQLITE_OMIT_LOAD_EXTENSION), then the following will assign default pointers:

#ifndef _WIN32
    if ((pApi == nullptr) || (pApi->create_module == nullptr))
    {
        pApi = &OGRSQLITE_static_routines;
    }
#endif

And sqlite3_api is declared static at line 144 (static SQLITE_EXTENSION_INIT1), so I don't see what could mess it up behind our back

@lnicola
Copy link
Member Author

lnicola commented Jan 12, 2024

We only call GDALAllRegister from a single thread (using something like call_once. I'm not sure what kind of ordering it uses, but one possibility is that sqlite3_api is initialized on one thread, while another one sees it as null. That's likely to just initialize it twice, but..

@lnicola
Copy link
Member Author

lnicola commented Jan 12, 2024

The other possibility is that it's racing against libproj's usage of SQLite. Though it seems less likely (I didn't check, but I assume it's not setting itself up as an extension or anything weird like that).

@lnicola
Copy link
Member Author

lnicola commented Jan 13, 2024

I added that debug-print (with the thread id too) and the result was not what I expected:

Successful run:

running 4 tests
Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmpPailY2.gpkg'
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
.[0x7f04e39566c0] pApi=0x7f05ea1faee0, pApi->create_module = 0x7f05ea149a30, pApi->create_module_v2 = 0x7f05ea149a40
ERROR 1: PROJ: hgridshift: could not find required grid(s).
ERROR 1: PROJ: pipeline: Pipeline: Bad step definition: proj=hgridshift (File not found or invalid)
.[0x7f04e39566c0] pApi=0x7f05ea1faee0, pApi->create_module = 0x7f05ea149a30, pApi->create_module_v2 = 0x7f05ea149a40
.ERROR 6: Cannot find coordinate operations from `EPSG:6491' to `EPSG:28992'
.
test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 261 filtered out; finished in 0.04s

Failed run:

running 4 tests
Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmpVbt6oy.gpkg'
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
ERROR 1: PROJ: hgridshift: could not find required grid(s).
ERROR 1: PROJ: pipeline: Pipeline: Bad step definition: proj=hgridshift (File not found or invalid)
..fish: Job 1, 'target/release/deps/gdal-a5f1a0…' terminated by signal SIGSEGV (Address boundary error)

(tested on GDAL 3.7.3 with SQLite 3.42.0)

To reproduce:

$ DEBUGINFOD_URLS=https://debuginfod.fedoraproject.org/ LD_LIBRARY_PATH=~/Projects/gdal/install/lib64 GDAL_INCLUDE_DIR=~/Projects/gdal/install/include GDAL_LIB_DIR=~/Projects/gdal/install/lib64 GDAL_VERSION=3.7.3 GDAL_HOME=~/Projects/gdal/install/share  while gdb -ex="set debuginfod enabled on" -ex=r -ex=quit --args target/release/deps/gdal-a5f1a0f14e3eca4c -q --test-threads 3 -- spatial_ref::transform_opts::tests::set_coordinate_operation spatial_ref::transform_opts::tests::invalid_transformation vector::layer::tests::test_create_layer_options vector::layer::tests::test_field_in_layer; end

# or

LD_LIBRARY_PATH=~/Projects/gdal/install/lib64 GDAL_INCLUDE_DIR=~/Projects/gdal/install/include GDAL_LIB_DIR=~/Projects/gdal/install/lib64 GDAL_VERSION=3.7.3 GDAL_HOME=~/Projects/gdal/install/share  while target/release/deps/gdal-a5f1a0f14e3eca4c -q --test-threads 3 -- spatial_ref::transform_opts::tests::set_coordinate_operation spatial_ref::transform_opts::tests::invalid_transformation vector::layer::tests::test_create_layer_options vector::layer::tests::test_field_in_layer; end

(for POSIX shells that should be while ...;do done or something like that, and target/release/deps/gdal-a5f1a0f14e3eca4c is from the output of cargo test --release)

@lnicola
Copy link
Member Author

lnicola commented Jan 13, 2024

With more logging:

running 4 tests
Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmp3pxmLj.gpkg'
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
.[0x7f9e04f566c0] OGR2SQLITE_Register: entry
[0x7f9e04f566c0] OGR2SQLITE_Register: exit, sqlite3_auto_extension() -> 0
[0x7f9e04f566c0] OGR2SQLITE_static_register pApi=0x7f9f0bd60ee0, pApi->create_module = 0x7f9f0bcafa30, pApi->create_module_v2 = 0x7f9f0bcafa40
[0x7f9e04f566c0] OGR2SQLITEModule::Setup, sqlite3_api = 0x7f9f0bd60ee0
ERROR 1: PROJ: hgridshift: could not find required grid(s).
ERROR 1: PROJ: pipeline: Pipeline: Bad step definition: proj=hgridshift (File not found or invalid)
.[0x7f9e04f566c0] OGR2SQLITE_Register: entry
[0x7f9e04f566c0] OGR2SQLITE_Register: exit, sqlite3_auto_extension() -> 0
[0x7f9e04f566c0] OGR2SQLITE_static_register pApi=0x7f9f0bd60ee0, pApi->create_module = 0x7f9f0bcafa30, pApi->create_module_v2 = 0x7f9f0bcafa40
[0x7f9e04f566c0] OGR2SQLITEModule::Setup, sqlite3_api = 0x7f9f0bd60ee0
.ERROR 6: Cannot find coordinate operations from `EPSG:6491' to `EPSG:28992'

running 4 tests
Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmpyoCohp.gpkg'
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
ERROR 1: PROJ: hgridshift: could not find required grid(s).
ERROR 1: PROJ: pipeline: Pipeline: Bad step definition: proj=hgridshift (File not found or invalid)
.[0x7f6bb75576c0] OGR2SQLITE_Register: entry
[0x7f6bb75576c0] OGR2SQLITE_Register: exit, sqlite3_auto_extension() -> 0
.[0x7f6bb75576c0] OGR2SQLITEModule::Setup, sqlite3_api = (nil)
fish: Job 1, 'target/release/deps/gdal-a5f1a0…' terminated by signal SIGSEGV (Address boundary error)

So, without having looked in detail at the rest of the code:

  • we call GDALAllRegister OGRSQLiteBaseDataSource::OpenOrCreateDB -> OGR2SQLITE_Register -> sqlite3_auto_extension from , which stores the pointer for later
  • sqlite3_open calls openDatabase, which calls all extensions via sqlite3AutoLoadExtensions
  • our extension (OGR2SQLITE_static_register) should initialize sqlite3_api but doesn't get called
  • OGR2SQLITEModule::Setup tries to call sqlite3_api->sqlite3_create_module_v2, but gets a NULL
  • all of this on the same thread (?!)

@rouault
Copy link
Contributor

rouault commented Jan 13, 2024

  • we call GDALAllRegister -> OGR2SQLITE_Register

OGR2SQLITE_Register is only called by OGRSQLiteBaseDataSource::OpenOrCreateDB(), not at GDALAllRegister() time

@lnicola
Copy link
Member Author

lnicola commented Jan 13, 2024

Of course, not sure what I was seeing. With more logging

running 4 tests
Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmpBMW5FO.gpkg'
[0x7f7d595566c0] GDALGeoPackageDataset::OpenOrCreateDB()
[0x7f7d595566c0] OGRSQLiteBaseDataSource::OpenOrCreateDB(..., 0, ...)
[0x7f7d595566c0] OGRSQLiteBaseDataSource::LoadExtensions
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
.[0x7f7d595566c0] OGRSQLiteDataSource::OpenOrCreateDB(..., 1)
[0x7f7d595566c0] OGRSQLiteBaseDataSource::OpenOrCreateDB(..., 1, ...)
[0x7f7d595566c0] OGR2SQLITE_Register: entry
[0x7f7d595566c0] OGR2SQLITE_Register: exit, sqlite3_auto_extension() -> 0
[0x7f7d595566c0] OGR2SQLITE_static_register pApi=0x7f7e5fdfaee0, pApi->create_module = 0x7f7e5fd49a30, pApi->create_module_v2 = 0x7f7e5fd49a40
[0x7f7d595566c0] OGR2SQLITEModule::Setup, sqlite3_api = 0x7f7e5fdfaee0
[0x7f7d595566c0] OGRSQLiteBaseDataSource::LoadExtensions
[0x7f7d595566c0] OGRSQLiteDataSource::OpenOrCreateDB(..., 1)
[0x7f7d595566c0] OGRSQLiteBaseDataSource::OpenOrCreateDB(..., 1, ...)
[0x7f7d595566c0] OGR2SQLITE_Register: entry
[0x7f7d595566c0] OGR2SQLITE_Register: exit, sqlite3_auto_extension() -> 0
[0x7f7d595566c0] OGR2SQLITE_static_register pApi=0x7f7e5fdfaee0, pApi->create_module = 0x7f7e5fd49a30, pApi->create_module_v2 = 0x7f7e5fd49a40
ERROR 1: PROJ: hgridshift: could not find required grid(s).
ERROR 1: PROJ: pipeline: Pipeline: Bad step definition: proj=hgridshift (File not found or invalid)
[0x7f7d595566c0] OGR2SQLITEModule::Setup, sqlite3_api = 0x7f7e5fdfaee0
[0x7f7d595566c0] OGRSQLiteBaseDataSource::LoadExtensions
..ERROR 6: Cannot find coordinate operations from `EPSG:6491' to `EPSG:28992'
.
test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 261 filtered out; finished in 0.04s


running 4 tests
Warning 1: GPKG: bad application_id=0x00000000 on '/tmp/.tmp2zMhPx.gpkg'
[0x7f1dfb5566c0] GDALGeoPackageDataset::OpenOrCreateDB()
[0x7f1dfb5566c0] OGRSQLiteBaseDataSource::OpenOrCreateDB(..., 0, ...)
[0x7f1dfb5566c0] OGRSQLiteBaseDataSource::LoadExtensions
ERROR 1: Layer new already exists, CreateLayer failed.
Use the layer creation option OVERWRITE=YES to replace it.
ERROR 1: PROJ: hgridshift: could not find required grid(s).
ERROR 1: PROJ: pipeline: Pipeline: Bad step definition: proj=hgridshift (File not found or invalid)
.[0x7f1dfb7576c0] OGRSQLiteDataSource::OpenOrCreateDB(..., 1)
[0x7f1dfb7576c0] OGRSQLiteBaseDataSource::OpenOrCreateDB(..., 1, ...)
[0x7f1dfb7576c0] OGR2SQLITE_Register: entry
[0x7f1dfb7576c0] OGR2SQLITE_Register: exit, sqlite3_auto_extension() -> 0
.[0x7f1dfb7576c0] OGR2SQLITEModule::Setup, sqlite3_api = (nil)
fish: Job 1, 'target/release/deps/gdal-a5f1a0…' terminated by signal SIGSEGV (Address boundary error)

@rouault
Copy link
Contributor

rouault commented Jan 13, 2024

I still don't manage to reproduce within a fedora:39 Docker image, even while looping for ever.
I've been digging into sqlite3 code source, and one very slightly suspicious thing is this optimization in sqlite3AutoLoadExtensions(): https://github.com/sqlite/sqlite/blob/89efa897780db03eac974eb6b0e041cfb7c39733/src/loadext.c#L873 , where wsdAutoext.nExt is tested against 0 outside of the SQLITE_MUTEX_STATIC_MAIN mutex that is normally used otherwise. But this does still seem OK given my understanding of multithreading and mutexes.

My hypothesis to explain what you observe would be:

  • thread A does PROJ stuff which opens proj.db, which calls sqlite3AutoLoadExtensions() and sees wsdAutoext.nExt == 0 (OGR2SQLITE_Register() having not yet been called)
  • thread B calls OGRSQLiteDataSource::OpenOrCreateDB(..., 1), which calls OGR2SQLITE_Register(), which calls sqlite3_auto_extension(), which sets wsdAutoext.nExt = 1, but within the mutex
  • thread B opens a sqlite3 database, which calls sqlite3AutoLoadExtensions(), but for a reason I don't understand, it would still see the value of wsdAutoext.nExt == 0 that was seen by thread A, instead of the value 1 set previously under the mutex by thread B. But I don't think that's possible... Anyway thinking out loud in case as I've no better idea. (another possibility would be that some code would call sqlite3_reset_auto_extension(), which has the effect of reseting wsdAutoext.nExt to 0, but neither GDAL nor PROJ do that)

If you have the possibility of building sqlite from source, one possibility would be to try to remove the optim https://github.com/sqlite/sqlite/blob/89efa897780db03eac974eb6b0e041cfb7c39733/src/loadext.c#L873 and see if that makes any difference
Or instrument sqlite3_reset_auto_extension() to see if some unexpected code would call it...

@rouault
Copy link
Contributor

rouault commented Jan 13, 2024

OSGeo/gdal#9068 should likely stop the segfault, but there's still something missing to understand the full picture

@ChristianBeilschmidt
Copy link
Contributor

I don't know if I can add something valuable to the dscussion, but we've recently added cargo as a dependency and our test suite ran with 0.76 but with 0.77 (geo-engine/geoengine#929) one GdalOpenEx call with georust/gdal suddenly had a SIGSEGV.

Looking at this thread I noticed that 0.77 got a dependency of rusqlite, which again brought libsqlite3-sys=0.28. Removing this dependency seemed to remove the SIGSEGV… which is very scary.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants