`put` a value without specifying a TTL seems to set the TTL to 0 instead of infinity

guizmaii commented 6 years ago

Hi,

As explained on Twitter: https://twitter.com/guizmaii/status/995007834160091136, I noticed that if I didn't provide a TTL to the put function, the data seems to be immediately deleted.

Before this commit: https://github.com/guizmaii/scala-distances/pull/28/commits/aa83c1029ce6c8fae1c4ac2e0ba7933c09684878#diff-4623d4a0f3c23d57b700728ba11112f6R85, my tests were something like this:

    "cache" should {
      "save things" in {
        forAll(totoGen) { toto: Toto =>
          runSync(cache.set(key)(toto)) shouldBe expectedJson(toto) // `set` is just a proxy to your `put` function
          runSync(cache.get[Toto](key)) shouldBe toto
        }
      }
    }

and it fails with to following error:

[info]     - should save things *** FAILED ***
[info]       TestFailedException was thrown during property evaluation.
[info]         Message: None was not equal to Some(Toto(titi,78,DirectedPath(LatLong(1.0,1.0),LatLong(1.0,1.0),List(Bicycling)),PostalCode(m1H2y),NonAmbigueAddress(,,N7ewJ,,),Distance(1,0 m,1 second)))
[info]         Location: (CacheProviderSpec.scala:86)
[info]         Occurred when passed generated values (
[info]           arg0 = Toto(titi,78,DirectedPath(LatLong(1.0,1.0),LatLong(1.0,1.0),List(Bicycling)),PostalCode(m1H2y),NonAmbigueAddress(,,N7ewJ,,),Distance(1,0 m,1 second))
[info]         )

When I add the TTL to the function params:

    "cache" should {
      "save things" in {
        forAll(totoGen) { toto: Toto =>
          runSync(cache.set(key)(toto, Some(1 day))) shouldBe expectedJson(toto)
          runSync(cache.get[Toto](key)) shouldBe Some(toto)
        }
      }
    }

The test suite passes.

My tests are written againts Caffeine and Redis backend. They have both the problem.

You can find my code here: https://github.com/guizmaii/scala-distances/pull/28

cb372 commented 6 years ago

OK, something really weird is happening here.

Firstly I checked the behaviour of ScalaCache itself, because this would be a huge bug if true. ScalaCache seems fine. We have tests for calling put without a TTL, e.g. here.

Then I cloned your project and checked out commit aa83c1029c, the one where you fixed the tests by adding a TTL.

This is where things get interesting...

Version 1

        forAll(totoGen) { toto: Toto =>
          runSync(cache.set(key)(toto, Some(1 day))) shouldBe expectedJson(toto)
          runSync(cache.get[Toto](key)) shouldBe Some(toto)
        }

The tests pass reliably.

Version 2

        forAll(totoGen) { toto: Toto =>
          runSync(cache.set(key)(toto, None)) shouldBe expectedJson(toto)
          runSync(cache.get[Toto](key)) shouldBe Some(toto)
        }

The tests pass reliably.

Version 3

        forAll(totoGen) { toto: Toto =>
          runSync(cache.set(key)(toto)) shouldBe expectedJson(toto)
          runSync(cache.get[Toto](key)) shouldBe Some(toto)
        }

The tests fail reliably.

This doesn't make any sense to me, as the only difference is specifying the ttl argument to be the same value as the argument's default.

I verified with a println inside CacheProvider#set that the ttl passed to ScalaCache is None in both cases.

I'll keep investigating...

cb372 commented 6 years ago

I worked out what's going on! You've been bitten by the dreaded _*.

I added a dependency on logback and set the log level to DEBUG so I could see the ScalaCache logs. This shows the raw string keys that are being used for cache writes and lookups.

Here's how they look for each of the versions above.

Version 1

write = WrappedArray(49e46d37-cc90-46d5-bf96-d2506b14f453)
read = WrappedArray(49e46d37-cc90-46d5-bf96-d2506b14f453)

Version 2

write = WrappedArray(6902e992-81fa-433a-bad9-7e7aaa6d19c6)
read = WrappedArray(6902e992-81fa-433a-bad9-7e7aaa6d19c6)

Version 3

write = List(b8e7e270-909d-485b-906c-66e7a81f807c)
read = WrappedArray(b8e7e270-909d-485b-906c-66e7a81f807c)

Because your CacheProvider's methods accept the key as _* but do not pass them down to ScalaCache as _*, you've unfortunately stumbled upon some weird and unspecified behaviour of the Scala compiler.

If you fix the CacheProvider to pass the key as _*:

  def get[A](key: Any*)(implicit decoder: Decoder[A]): AIO[Option[A]] =
    OptionT(innerCache.get(key: _*)).mapFilter(decoder.decodeJson(_).toOption).value

  def set[A](key: Any*)(value: A, ttl: Option[Duration] = None)(implicit encoder: Encoder[A]): AIO[Json] = {
    val jsonValue = encoder.apply(value)
    innerCache.put(key: _*)(jsonValue, ttl).map(_ => jsonValue)
  }

then the tests pass, and you can see in the logs that it is using a sensible cache key (e.g. 7c68aaec-1c25-4c18-afae-bdbcacaffd9e) for both reading and writing.

I've previously run into this exact problem inside ScalaCache itself. It's a very nasty trap.

guizmaii commented 6 years ago

Oh ! I'm really sorry I bothered you with a bug in my code.

Thanks a lot for the time you took.

cb372 / scalacache