search

sksamuel / aedile

Kotlin Wrapper for Caffeine
Apache License 2.0
164 stars 15 forks source link

Dispatcher thread is incorrect #20

Closed trietsch closed 1 year ago

trietsch commented 1 year ago

While investigating exception handling by Aedile, I noticed that the thread is incorrect when providing a lambda to compute the value if absent.

import com.sksamuel.aedile.core.caffeineBuilder
import org.slf4j.LoggerFactory

suspend fun main() {
    val log = LoggerFactory.getLogger("caffeine")
    val cache = caffeineBuilder<String, String>().build()

    repeat(10) {
        log.info(cache.get(it.toString()) { "value" })
    }
}

Which results in:

11:28:17.437 [main] INFO  caffeine - value 
11:28:17.442 [main] INFO  caffeine - value 
11:28:17.442 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.442 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.444 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.444 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.444 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.444 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.444 [DefaultDispatcher-worker-3] INFO  caffeine - value 
11:28:17.445 [DefaultDispatcher-worker-3] INFO  caffeine - value

Sometimes it shows 3 on the main thread, but in this example 2. I've looked at the sources of Aedile, but I can't figure out exactly what's wrong. The CoroutineScope is correctly set and used if I'm correct. Any ideas?

trietsch commented 1 year ago

Alright, I've done some tweaks and it seems to be my own misconception about coroutines. When doing the following:

import com.sksamuel.aedile.core.caffeineBuilder
import org.slf4j.LoggerFactory
import kotlinx.coroutines.runBlocking

fun main() {
    val log = LoggerFactory.getLogger("caffeine")
    val cache = caffeineBuilder<String, String>().build {
        log.info(it)
        "value"
    }

    repeat(10) {
        val res = runBlocking {
            cache.get(it.toString())
        }
        log.info(res)
    }
}

You get:

11:46:52.724 [DefaultDispatcher-worker-1] INFO  caffeine - 0 
11:46:52.728 [main] INFO  caffeine - value 
11:46:52.728 [DefaultDispatcher-worker-3] INFO  caffeine - 1 
11:46:52.728 [main] INFO  caffeine - value 
11:46:52.728 [DefaultDispatcher-worker-2] INFO  caffeine - 2 
11:46:52.728 [main] INFO  caffeine - value 
11:46:52.728 [DefaultDispatcher-worker-2] INFO  caffeine - 3 
11:46:52.729 [main] INFO  caffeine - value 
11:46:52.729 [DefaultDispatcher-worker-2] INFO  caffeine - 4 
11:46:52.729 [main] INFO  caffeine - value 
11:46:52.729 [DefaultDispatcher-worker-2] INFO  caffeine - 5 
11:46:52.729 [main] INFO  caffeine - value 
11:46:52.729 [DefaultDispatcher-worker-2] INFO  caffeine - 6 
11:46:52.729 [main] INFO  caffeine - value 
11:46:52.729 [DefaultDispatcher-worker-2] INFO  caffeine - 7 
11:46:52.729 [main] INFO  caffeine - value 
11:46:52.729 [DefaultDispatcher-worker-2] INFO  caffeine - 8 
11:46:52.729 [main] INFO  caffeine - value 
11:46:52.729 [DefaultDispatcher-worker-2] INFO  caffeine - 9 
11:46:52.730 [main] INFO  caffeine - value

What happens is that the coroutine is moved to another thread. Closing ticket, sorry for the fuss :)