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

SIGSEGV: NativeSqliteDriver.notifyListeners() #4376

Closed
chrisbanes opened this issue Jul 14, 2023 · 12 comments
Closed

SIGSEGV: NativeSqliteDriver.notifyListeners() #4376

chrisbanes opened this issue Jul 14, 2023 · 12 comments
Assignees

Comments

@chrisbanes
Copy link

SQLDelight Version

2.0.0-rc02

Application Operating System

iOS

Describe the Bug

I've been seeing regular crashes in NativeSqliteDriver. Seems to happen when there's a multiple database operations happening at the same time.

I can repro this fairly easily in Tivi, but not sure how useful that is for debugging?

I'm currently running these operations on Dispatchers.IO. I'm wondering if I should move these database writes to a more constrained thread pool.

Stacktrace

0   Tivi                          	       0x106871a40 kfun:app.cash.sqldelight.driver.native.NativeSqliteDriver#notifyListeners(kotlin.Array<out|kotlin.String>...){} + 1244
1   Tivi                          	       0x106829b38 kfun:app.cash.sqldelight.BaseTransacterImpl#postTransactionCleanup(app.cash.sqldelight.Transacter.Transaction;app.cash.sqldelight.Transacter.Transaction?;kotlin.Throwable?;0:0?){0§<kotlin.Any?>}0:0 + 3728
2   Tivi                          	       0x106828ab0 kfun:app.cash.sqldelight.TransacterImpl.transactionWithWrapper#internal + 1288
3   Tivi                          	       0x106828574 kfun:app.cash.sqldelight.TransacterImpl#transactionWithResult(kotlin.Boolean;kotlin.Function1<app.cash.sqldelight.TransactionWithReturn<0:0>,0:0>){0§<kotlin.Any?>}0:0 + 148
4   Tivi                          	       0x1068271b8 kfun:app.cash.sqldelight.Transacter#transactionWithResult$default(kotlin.Boolean;kotlin.Function1<app.cash.sqldelight.TransactionWithReturn<0:0>,0:0>;kotlin.Int){0§<kotlin.Any?>}0:0 + 292
5   Tivi                          	       0x106979760 kfun:app.tivi.data.SqlDelightTransactionRunner#invoke(kotlin.Function0<0:0>){0§<kotlin.Any?>}0:0 + 264
6   Tivi                          	       0x1057ef594 kfun:app.tivi.data.shows.ShowStore.$<init>$lambda$3COROUTINE$1.invokeSuspend#internal + 452
7   Tivi                          	       0x1057ef958 kfun:app.tivi.data.shows.ShowStore.$<init>$lambda$3COROUTINE$1.invoke#internal + 292
8   Tivi                          	       0x1057efa6c kfun:app.tivi.data.shows.ShowStore.$<init>$lambda$3COROUTINE$1.$<bridge-NNNBNN>invoke#suspend(kotlin.Long;app.tivi.data.models.TiviShow;kotlin.coroutines.Continuation<kotlin.Any?>){}kotlin.Any?#internal + 208
9   Tivi                          	       0x105775c18 kfun:org.mobilenativefoundation.store.store5.impl.PersistentSourceOfTruth#write#suspend(1:0;1:1;kotlin.coroutines.Continuation<kotlin.Unit>){}kotlin.Any + 336
10  Tivi                          	       0x105787244 kfun:org.mobilenativefoundation.store.store5.impl.SourceOfTruthWithBarrier.$writeCOROUTINE$0.invokeSuspend#internal + 3104
11  Tivi                          	       0x105787b18 kfun:org.mobilenativefoundation.store.store5.impl.SourceOfTruthWithBarrier#write#suspend(1:0;1:2;kotlin.coroutines.Continuation<kotlin.Unit>){}kotlin.Any + 364
12  Tivi                          	       0x1057612e8 kfun:org.mobilenativefoundation.store.store5.impl.FetcherController.$<init>$lambda$3$lambda$2COROUTINE$2.invokeSuspend#internal + 1496
13  Tivi                          	       0x10576177c kfun:org.mobilenativefoundation.store.store5.impl.FetcherController.$<init>$lambda$3$lambda$2COROUTINE$2.invoke#internal + 276
14  Tivi                          	       0x105725e18 kfun:org.mobilenativefoundation.store.multicast5.StoreChannelManager.Actor.$doDispatchValueCOROUTINE$0.invokeSuspend#internal + 800
15  Tivi                          	       0x105726688 kfun:org.mobilenativefoundation.store.multicast5.StoreChannelManager.Actor.doDispatchValue#internal + 316
16  Tivi                          	       0x105724974 kfun:org.mobilenativefoundation.store.multicast5.StoreChannelManager.Actor.handle#internal + 600
17  Tivi                          	       0x105732c7c kfun:org.mobilenativefoundation.store.multicast5.StoreRealActor.$<init>$lambda$0COROUTINE$1.invokeSuspend#internal + 1144
18  Tivi                          	       0x104ede114 kfun:kotlin.coroutines.native.internal.BaseContinuationImpl#resumeWith(kotlin.Result<kotlin.Any?>){} + 600
19  Tivi                          	       0x1050cb840 kfun:kotlinx.coroutines.DispatchedTask#run(){} + 2604
20  Tivi                          	       0x1050f9638 kfun:kotlinx.coroutines.WorkerDispatcher.dispatch$lambda$0#internal + 156
21  Tivi                          	       0x1050fa230 kfun:kotlinx.coroutines.WorkerDispatcher.$dispatch$lambda$0$FUNCTION_REFERENCE$0.invoke#internal + 96
22  Tivi                          	       0x1050fa344 kfun:kotlinx.coroutines.WorkerDispatcher.$dispatch$lambda$0$FUNCTION_REFERENCE$0.$<bridge-UNN>invoke(){}#internal + 96
23  Tivi                          	       0x104eed8c0 WorkerLaunchpad + 196
24  Tivi                          	       0x1070037e4 Worker::processQueueElement(bool) + 2636
25  Tivi                          	       0x107002c3c (anonymous namespace)::workerRoutine(void*) + 220
26  libsystem_pthread.dylib       	       0x1b1838428 _pthread_start + 116
27  libsystem_pthread.dylib       	       0x1b1833648 thread_start + 8
@chrisbanes chrisbanes added the bug label Jul 14, 2023
chrisbanes added a commit to chrisbanes/tivi that referenced this issue Jul 15, 2023
Reads are limited to a dispatcher with a parallelism of 4, which
is equal to the newly set maximum connection readers on the SQLite
driver.

Writes are limited to a parallelism of 1, since that is what SQLDelight
will do under the hood anyway. This seems to fix concurrency issues
which result in crashes, such as sqldelight/sqldelight#4376.
chrisbanes added a commit to chrisbanes/tivi that referenced this issue Jul 15, 2023
Reads are limited to a dispatcher with a parallelism of 4, which
is equal to the newly set maximum connection readers on the SQLite
driver.

Writes are limited to a parallelism of 1, since that is what SQLDelight
will do under the hood anyway. This seems to fix concurrency issues
which result in crashes, such as sqldelight/sqldelight#4376.
chrisbanes added a commit to chrisbanes/tivi that referenced this issue Jul 15, 2023
Reads are limited to a dispatcher with a parallelism of 4, which
is equal to the newly set maximum connection readers on the SQLite
driver.

Writes are limited to a parallelism of 1, since that is what SQLDelight
will do under the hood anyway. This seems to fix concurrency issues
which result in crashes, such as sqldelight/sqldelight#4376.
@chrisbanes
Copy link
Author

For info: I moved all database write operations to a single parallelized coroutine dispatcher in chrisbanes/tivi#1400 which has definitely helped things. It still happens occassionally, but a whole lot less.

@FelixSubject211
Copy link

I had the same problem, I could imagine that it is because there are zero values in the array, but I don't understand why this is so.

chrisbanes added a commit to chrisbanes/tivi that referenced this issue Jul 27, 2023
@chrisbanes
Copy link
Author

chrisbanes commented Jul 27, 2023

As linked above, I think I've found the reason this is happening, although I don't know why. For some reason null entries are being added to the listenersToNotify list in notifyListeners(), which then means that queryResultsChanged is called on a null object.

Looks like a K/N bug to me somewhere, but tricky to work out exactly where this is coming from. Might be something to do with using a MutableMap + concurrency. My workaround moves the root listeners to use MutableSets instead, with a filterNotNull() to be extra safe. MutableSet is probably better anyway, as it's a LinkedHashSet underneath so will maintain insertion order.

I'll give it a few days or so to see if the workaround fixes the crashes (which are happening ~5 times per day for me). If it does, I'll send a PR.

chrisbanes added a commit to chrisbanes/tivi that referenced this issue Jul 27, 2023
@AlecKazakova
Copy link
Collaborator

wowowow, thank you for investigating

@kpgalligan
Copy link
Collaborator

Looking at it, the map was this:

private class BasicMutableMapShared<K : Any, V : Any> : BasicMutableMap<K, V> {
  private val lock = PoolLock(reentrant = true)
  private val data = mutableMapOf<K, V>()

  override fun getOrPut(key: K, block: () -> V): V = lock.withLock { data.getOrPut(key, block) }

  override val values: Collection<V>
    get() = lock.withLock { data.values }

  override fun put(key: K, value: V) {
    lock.withLock { data[key] = value }
  }

  override fun get(key: K): V? = lock.withLock { data[key] }

  override fun remove(key: K) {
    lock.withLock { data.remove(key) }
  }

  override val keys: Collection<K>
    get() = lock.withLock { data.keys }

  override fun cleanUp(block: (V) -> Unit) {
    lock.withLock {
      data.values.forEach(block)
    }
  }
}

That was added last year to support both the strict memory model and the current one. Then this year, the driver was changed to use a regular mutable map without any locking. Right now, I don't know if that's causing issues, but if nowhere up the call chain is enforcing thread safety, it's certainly a potential problem.

I want to dig through those changes to see if there are any other places where collections have been changed as well. Will also look into the workaround.

Taking a step back, I'm not sure pulling out the map I had in buys much because it was written to support both memory models, but I don't know the scope of the changes yet.

So, summary, non-thread-safe map in a place likely to be interacting with multiple threads.

@kpgalligan
Copy link
Collaborator

Just a note. On map vs set, it was using a map because the concurrent map implementation could implement a set without needing to actually write a different set implementation for concurrency. Or, to state differently, I took the lazy option :) Strictly speaking, a set is what should be used there.

@kpgalligan
Copy link
Collaborator

So, simple "fix", assuming it does actually fix the issue: #4567.

Pretty big problem, so we should get this out there.

On why the workaround potentially didn't solve the issue, it looks like there are still different threads for read/write. I'm going somewhat by memory here, but the query listener would likely be added by the read, but query listener notifications would run in the thread that updated the DB, so there's still collection access from multiple threads. A reduction in crashes, but not a completely prevention, makes sense in that context.

However, race conditions are tough. I'd like to see what happens out in the wild with this change before I say it's "fixed", in case there's something else going on as well.

@kpgalligan
Copy link
Collaborator

@chrisbanes I took a look at tivi and notices the workaround above has changed some. I'm wondering about this:

private class WorkaroundNativeSqliteDriver(
    schema: SqlSchema<QueryResult.Value<Unit>>,
    name: String,
    maxReaderConnections: Int = 1,
) : SqlDriver by NativeSqliteDriver(schema, name, maxReaderConnections) {
    // We can't use a mutable collection in a HashMap, as the value's hash
    // will change as the collection changes, which then makes HashMap happy.
    // In K/N this causes an IllegalStateException (but not on JVM)
    private val listeners = mutableMapOf<String, Set<Query.Listener>>()

We can't use a mutable collection in a HashMap, as the value's hash will change as the collection changes

Is this a known issue or observed behavior? I wouldn't expect the hash of the value side to matter vs the key. I did get IllegalStateException when testing mutable collections from multiple threads without any protection. With the lock on, it works fine.

Example:

Uncaught Kotlin exception: kotlin.IllegalStateException: This cannot happen with fixed magic multiplier and grow-only hash array. Have object hashCodes changed?
Uncaught Kotlin exception: kotlin.IllegalStateException: This cannot happen with fixed magic multiplier and grow-only hash array. Have object hashCodes changed?
Uncaught Kotlin exception: kotlin.IllegalStateException: This cannot happen with fixed magic multiplier and grow-only hash array. Have object hashCodes changed?
Uncaught Kotlin exception: kotlin.ArrayIndexOutOfBoundsException
Invalid connection: com.apple.coresymbolicationd
Child process terminated with signal 11: Segmentation fault
    at 0   test.kexe                           0x102a66d0f        kfun:kotlin.Throwable#<init>(){} + 99 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Throwable.kt:29:21)
    at 0   test.kexe                           0x102a66c97        kfun:kotlin.Throwable#<init>(kotlin.String?){} + 123 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Throwable.kt:25:37)    at 1   test.kexe                           0x102a5ffab        kfun:kotlin.Exception#<init>(){} + 91 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:21:28)    at 0   test.kexe                           0x102a66c97        kfun:kotlin.Throwable#<init>(kotlin.String?){} + 123 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Throwable.kt:25:37)

    at 1   test.kexe                           0x102a60047        kfun:kotlin.Exception#<init>(kotlin.String?){} + 119 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:23:44)
    at 2   test.kexe                           0x102a60123        kfun:kotlin.RuntimeException#<init>(){} + 91 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:32:28)
    at 2   test.kexe                           0x102a601bf        kfun:kotlin.RuntimeException#<init>(kotlin.String?){} + 119 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:34:44)

    at 3   test.kexe                           0x102a609f3        kfun:kotlin.IndexOutOfBoundsException#<init>(){} + 91 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:90:28)
    at 3   test.kexe                           0x102a6079f        kfun:kotlin.IllegalStateException#<init>(kotlin.String?){} + 119 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:70:44)    at 1   test.kexe                           0x102a60047        kfun:kotlin.Exception#<init>(kotlin.String?){} + 119 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:23:44)

    at 4   test.kexe                           0x102a60b6b        kfun:kotlin.ArrayIndexOutOfBoundsException#<init>(){} + 91 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:97:21)
    at 4   test.kexe                           0x102ac4e97        kfun:kotlin.collections.HashMap.rehash#internal + 627 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/libraries/stdlib/native-wasm/src/kotlin/collections/HashMap.kt:249:23)    at 2   test.kexe                           0x102a601bf        kfun:kotlin.RuntimeException#<init>(kotlin.String?){} + 119 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/Exceptions.kt:34:44)    at 5   test.kexe                           0x102a83dfb        ThrowArrayIndexOutOfBoundsException + 131 (/opt/buildAgent/work/acafc8c59a79cc1/kotlin/kotlin-native/runtime/src/main/kotlin/kotlin/native/internal/RuntimeUtils.kt:25:11)

@chrisbanes
Copy link
Author

chrisbanes commented Oct 7, 2023

Sorry, I missed this reply. Let me remove my workaround in Tivi and see if #4567 fixes it 🤞

@AlecKazakova any chance for a 2.1.0-alpha01 soon?

chrisbanes added a commit to chrisbanes/tivi that referenced this issue Oct 7, 2023
It contains a fix for sqldelight/sqldelight#4376,
so testing that out without my workaround.
chrisbanes added a commit to chrisbanes/tivi that referenced this issue Oct 7, 2023
It contains a fix for sqldelight/sqldelight#4376. Testing that out without 
my workaround to verify the fix.
@chrisjenx
Copy link
Contributor

@chrisbanes did you notice the issue go away? We just started seeing this issue too :(

@chrisbanes
Copy link
Author

Yes, I'm currently using 2.1.0-SNAPSHOT and haven't seen the issue since.

@chrisjenx
Copy link
Contributor

Looks like this is in 2.0.1? Can probably close this out?

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

No branches or pull requests

6 participants