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.

Sign up for GitHub

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

Jump to bottom

Mutex is not locked - inside search call #244

Closed
falkorichter opened this issue Jan 4, 2021 · 15 comments · Fixed by #284
Closed

Mutex is not locked - inside search call #244

falkorichter opened this issue Jan 4, 2021 · 15 comments · Fixed by #284

Comments

@falkorichter
Copy link

We´re seeing quite some
IllegalStateException Mutex is not locked
in the 1.5.0 of the Algolia SDK in our Android app. The stack trace indicates like there is little of our code involvements.

We have a suspicion this relates to two consecutive calls to com.algolia.search.client.Index.search() in a clean Android with Kotlin Coroutines Environment. All searches run in the same coroutine context.

java.lang.IllegalStateException: Mutex is not locked
    at na1.b(Mutex.kt:3)
    at ma1$a.b(Mutex.kt:1)
    at vl0.g(Logging.kt:1)
    at vl0.a(Logging.kt:1)
    at vl0$a$a.v(Logging.kt:11)
    at w31.f(ContinuationImpl.kt:3)
    at kotlinx.coroutines.a1.run(DispatchedTask.kt:17)
    at y91.J(CoroutineScheduler.kt:1)
    at y91$a.c(CoroutineScheduler.kt:4)
    at y91$a.m(CoroutineScheduler.kt:4)
    at y91$a.run(CoroutineScheduler.kt:1)

We are puzzled, We would suspect that the Mutex is there to limit parallel requests, but since the unlocking failes in the
public suspend inline fun <T> Mutex.withLock(owner: Any? = null, action: () -> T): T {

finally {
        unlock(owner)
    }

the unlock fails:

public override fun unlock(owner: Any?) {
@falkorichter falkorichter changed the title Mutex is not locked - inside se Mutex is not locked - inside search call Jan 4, 2021
@aallam
Copy link
Member

aallam commented Jan 5, 2021

Hi @falkorichter, thank you for reporting this.

Unfortunately, I couldn't reproduce the issue! Does the exception show up in the latest version of the library too? And can you please provide a code snippet to reproduce the error?

Thank you!

@falkorichter
Copy link
Author

This is the stacktrace we´re getting:

com.ajnsnewmedia.kitchenstories.datasource.algolia.DefaultAlgoliaIndexWrapper in a at line 1
com.ajnsnewmedia.kitchenstories.datasource.algolia.AlgoliaIndexWrapper$DefaultImpls in a at line 1
com.ajnsnewmedia.kitchenstories.datasource.algolia.AlgoliaDataSource$searchForCategories$1$1 in u at line 1

We are basically just wrapping your SDK:

return rxSingle(dispatcherProvider.main()) {
            withContext(dispatcherProvider.io()) { index.search(algoliaQuery).hits.deserializeSafely(AlgoliaCategory.serializer()) }
        }

and dispatcherProvider.io() returns Dispatchers.IO, nothing special there.

@CoreFloDev
Copy link

Hi

I got the same issue, it seems to come from Ktor logging as per Kotlin/kotlinx.coroutines#2683, can you disable it?

obfuscated stack trace for reference:

Non-fatal Exception: java.lang.IllegalStateException: Mutex is not locked
       at kotlinx.coroutines.sync.MutexImpl.unlock(MutexImpl.java:308)
       at kotlinx.coroutines.sync.Mutex$DefaultImpls.unlock$default(Mutex.java:87)
       at io.ktor.client.features.logging.Logging.doneLogging(Logging.java:67)
       at io.ktor.client.features.logging.Logging.access$doneLogging(Logging.java:25)
       at io.ktor.client.features.logging.Logging$Companion$install$1.invokeSuspend(Logging.java:171)
       at io.ktor.client.features.logging.Logging$Companion$install$1.invoke(Logging.java:1)
       at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.java:248)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.java:116)
       at io.ktor.util.pipeline.SuspendFunctionGun.execute(SuspendFunctionGun.java:136)
       at io.ktor.util.pipeline.Pipeline.execute(Pipeline.java:79)
       at io.ktor.client.features.HttpSend$DefaultSender.execute(HttpSend.java:128)
       at io.ktor.client.features.HttpSend$Feature$install$1.invokeSuspend(HttpSend.java:89)
       at io.ktor.client.features.HttpSend$Feature$install$1.invoke(HttpSend.java:1)
       at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.java:248)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.java:116)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceedWith(SuspendFunctionGun.java:126)
       at io.ktor.client.features.HttpPlainText$Feature$install$1.invokeSuspend(HttpPlainText.java:140)
       at io.ktor.client.features.HttpPlainText$Feature$install$1.invoke(HttpPlainText.java:1)
       at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.java:248)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.java:116)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceedWith(SuspendFunctionGun.java:126)
       at io.ktor.client.features.HttpCallValidator$Companion$install$1.invokeSuspend(HttpCallValidator.java:112)
       at io.ktor.client.features.HttpCallValidator$Companion$install$1.invoke(HttpCallValidator.java:1)
       at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.java:248)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.java:116)
       at io.ktor.client.features.HttpRequestLifecycle$Feature$install$1.invokeSuspend(HttpRequestLifecycle.java:37)
       at io.ktor.client.features.HttpRequestLifecycle$Feature$install$1.invoke(HttpRequestLifecycle.java:1)
       at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.java:248)
       at io.ktor.util.pipeline.SuspendFunctionGun.proceed(SuspendFunctionGun.java:116)
       at io.ktor.util.pipeline.SuspendFunctionGun.execute(SuspendFunctionGun.java:136)
       at io.ktor.util.pipeline.Pipeline.execute(Pipeline.java:79)
       at io.ktor.client.HttpClient.execute(HttpClient.java:191)
       at io.ktor.client.statement.HttpStatement.executeUnsafe(HttpStatement.java:104)
       at com.algolia.search.endpoint.internal.EndpointSearchImpl.search(EndpointSearchImpl.java:237)
       at com.algolia.search.client.internal.IndexImpl.search(IndexImpl.java:2)
       at com.algolia.search.endpoint.EndpointSearch$DefaultImpls.search$default(EndpointSearch.java:30)
       at com.farmdrop.customer.common.data.repository.AlgoliaSearchRepository$getProductIdsForSearchAlgoliaNetwork$1.invokeSuspend(AlgoliaSearchRepository.java:53)
       at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(BaseContinuationImpl.java:33)
       at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.java:106)
       at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.java:571)
       at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.java:750)
       at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.java:678)
       at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.java:665)

Thanks,
Flo

@falkorichter
Copy link
Author

I´m no longer on the project, I pinged the team to follow up on it.

@dominikgold
Copy link

Hi @CoreFloDev, thanks a lot for your reply! this is exactly the issue we're facing. We're now passing the following to our ConfigurationSearch:

httpClientConfig = {
    install(Logging) {
        filter { false }
    }
}

which seems to prevent the logging code in ktor from running. That was extremely helpful, thanks again!

@CoreFloDev
Copy link

But that's just an hotfix, they shouldn't have any logging code at all on prod as it slows down a bit every request and take space in the apk for nothing

@CoreFloDev
Copy link

@aallam Can you also please remove that logging lib from the ktor production instance?

please see https://ktor.io/docs/client.html#features for reference

You can keep it for development if you need it but it doesn't make sense to have it running on prod as per:

algoliasearch-client-kotlin/client/src/commonMain/kotlin/com/algolia/search/configuration/internal/extension/HttpClient.kt

Line 32 in 19b8db8

install(Logging) {

Thanks Flo

@aallam
Copy link
Member

aallam commented Sep 10, 2021

Hi @CoreFloDev, by default, the logging level is LogLevel.NONE, which should not add any overhead.
For the error, do you know if the exception is still thrown even with LogLevel.NONE?

@CoreFloDev
Copy link

@aallam yes, it is still happening in production even with the LogLevel.None, I haven't changed that value and I can see a good amount of crashes related to that.

@aallam aallam mentioned this issue Sep 13, 2021
Merged
@aallam
Copy link
Member

aallam commented Sep 13, 2021

@CoreFloDev thank you for your reply, that was insightful.
I've created a PR for this, which should solve the issue if no logging is needed.

@parthm1015
Copy link

in which version this issue got fixed?

@aallam
Copy link
Member

aallam commented Aug 10, 2022

@parthm1015 starting from 1.10.0

@parthm1015
Copy link

@aallam i updated the algolia version to 1.10.0 but still i am getting errors. But i also observed that logging level i have kept is LogLevel.BODY. If i change it to LogLevel.NONE will it help resolve the issue?

@parthm1015
Copy link

can any one help me with this?

@aallam
Copy link
Member

aallam commented Oct 4, 2022

Hi @parthm1015, yes, you need to use LogLevel.NONE to disable ktor's logging plugin

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix: logging feature install on LogLevel.NONE algolia/algoliasearch-client-kotlin
5 participants
@falkorichter @CoreFloDev @aallam @dominikgold @parthm1015