Mules reload hangs for the refresh time on first insert or lookup

[coltfred]

I was trying to use mules reload and ran into this issue. A bit of discussion happened on gitter here.

The main I used was as follows:

object Main3 extends IOApp {
  import cats.effect._
  import cats.implicits._
  import io.chrisdavenport.mules.reload._
  import scala.concurrent.duration._
  import io.chrisdavenport.mules.TimeSpec
  import io.chrisdavenport.mules.reload.AutoFetchingCache.RefreshConfig


  val refreshTime = 5.seconds
  def printWithTime(msg: String): IO[Unit] =
    Timer[IO].clock.monotonic(TimeUnit.MILLISECONDS).flatMap(t => IO(println(t.toString + s":$msg")))
  def run(args: List[String]): IO[ExitCode] = {
    val cachingConfig = RefreshConfig(TimeSpec.unsafeFromDuration(refreshTime))

    for {
      _ <- printWithTime("Before cache")
      cache <- AutoFetchingCache.createCache[IO, Unit, Int](None, cachingConfig.some) { _ =>
        printWithTime("In Refresh").as(1)
      }
      _ <- printWithTime("After cache")
      v <- cache.fetch(())
      _ <- cache.insertWithTimeout(None)((), v)
      _ <- cache.lookupCurrent(())
      _ <- printWithTime("After first lookup")
      _ <- cache.lookupCurrent(())
      _ <- printWithTime("After second lookup")
      _ <- cache.lookup(())
      _ <- printWithTime("After third lookup")
      _ <- IO(println("Sleeping for 15 seconds")) *> IO.sleep(15.seconds)
      _ <- cache.lookupCurrent(())
      _ <- printWithTime("After fourth lookup")

    } yield ExitCode.Success
  }
}

This produces something like:

101639150:Before cache
101639477:After cache
101639479:In Refresh
101644510:In Refresh
101644513:After first lookup
101644515:After second lookup
101644519:After third lookup
Sleeping for 15 seconds
101649524:In Refresh
101654526:In Refresh
101659528:In Refresh
101659530:After fourth lookup

Note that the time between AfterCache and After first lookup is the same as refreshTime.

This is also shown by bumping the time to 15.seconds, which shows something like this:

101822782:Before cache
101823065:After cache
101823067:In Refresh
101838100:In Refresh
101838102:After first lookup

@ChristopherDavenport hypothesized that maybe the refresh was holding the Ref open during the initial insert.