'A test is using time, but is not advancing the test clock' in ZIO Test

Question

After migrating my Test to RC18, I get the following warning and the test is hanging:

Warning: A test is using time, but is not advancing the test clock, which may result in the test hanging. Use TestClock.adjust to manually advance the time.

I have the following test:

val testLayer: ZLayer[Live, Nothing, Loggings with Blocking with Clock] = (Console.live >>> loggings.consoleLogger) ++ Blocking.live ++ TestClock.default

testM("curl on invalid URL") {
          for {
            fork <- composer.curl("https://bad.xx", 1).flip.fork
            _ <- TestClock.adjust(3.second * 2)
            r <- fork.join
          } yield
            assert(r)(isSubtype[DockerComposerException](hasField("msg", _.msg.trim, equalTo("https://bad.xx could not be reached!"))))
        }.provideCustomLayer(testLayer)

I suspect, that I created the Layers wrong, as this is the only change I made for the migration.

Also the standard test from the documentation failed (time was 0):

testM("One can move time very fast") {
  for {
    startTime <- currentTime(TimeUnit.SECONDS)
    _         <- TestClock.adjust(Duration.fromScala(1 minute))
    endTime   <- currentTime(TimeUnit.SECONDS)
  } yield assert(endTime - startTime)(isGreaterThanEqualTo(60L))
}

When I define the Layers like:

val testLayer: ZLayer[Live, Nothing, Loggings with Blocking with Clock] = (Console.live >>> loggings.consoleLogger) ++ Blocking.live ++ Clock.live

the time is not adjusted at all.

Here is the code that I want to test:

  def curl(host: String, attempt: Int = 200): ZIO[Loggings with Clock, Throwable, Unit] = {
    ZIO.effect(
      Process(Seq("curl", "--output", "/dev/null", "--silent", "--head", "--fail", host)).!!
    ).flatMap(r =>
      info(s"\n$host is ready to use") *> ZIO.succeed()
    ).catchAll(t =>
      if (attempt == 0)
        ZIO.fail(DockerComposerException(s"\n$host could not be reached!", Some(t)))
      else
        info(s"still waiting ;(") *>
          ZIO.sleep(3.second) *>
          curl(host, attempt - 1)
    )
  }

So I want to fast forward ZIO.sleep(3.seconds).

Completely unrelated to your question, but STTP has nice ZIO support now, so no need to shell out to `curl`. — Thilo, Apr 09 '20 at 09:52

score 1 · Accepted Answer · answered Apr 09 '20 at 10:49

You need to call sleep(duration) after adjust(duration) to have the adjusted time reflected when you call currentTime. So the correct version of the example above is:

testM("One can move time very fast") {
  for {
    startTime <- currentTime(TimeUnit.SECONDS)
    _         <- TestClock.adjust(1.minute)
    _         <- ZIO.sleep(1.minute)
    endTime   <- currentTime(TimeUnit.SECONDS)
  } yield assert(endTime - startTime)(isGreaterThanEqualTo(60L))
}

Note that this is reflected in the current version of the documentation here but is not yet reflected on the website because we currently only publish changes when we do a release.

However, I don't think that is your issue as it looks like your effect is just using sleep.

I'm not able to reproduce your code entirely but the following slightly simplified example works correctly:

import zio._
import zio.clock.Clock
import zio.console.Console
import zio.duration._
import zio.test._
import zio.test.environment.TestClock

object ExampleSpec extends DefaultRunnableSpec {

  type Logging = Has[Logging.Service]
  object Logging {
    trait Service {
      def logLine(line: String): UIO[Unit]
    }
    val live: ZLayer[Console, Nothing, Logging] =
      ZLayer.fromService { console =>
        new Logging.Service {
          def logLine(line: String): UIO[Unit] =
            console.putStrLn(line)
        }
      }
    def logLine(line: String): ZIO[Logging, Nothing, Unit] =
      ZIO.accessM(_.get.logLine(line))
  }

  def effect(n: Int): ZIO[Clock with Logging, String, Unit] =
    if (n == 0) ZIO.fail("fail")
    else Logging.logLine("retrying") *> ZIO.sleep(3.seconds) *> effect(n -1)


  def spec = suite("ExampleSpec") {
    testM("test") {
      for {
        fiber <- effect(1).flip.fork
        _     <- TestClock.adjust(6.seconds)
        _     <- fiber.join
      } yield assertCompletes
    }.provideCustomLayer(Logging.live)
  }
}

Could there be something else going on in your test?

Thanks that works. I got mixed up in creating my own Layers. Is this possible at all, to do something I did with Clock. E.g. if I need Clock in my custom Layer? Clock.live >>> MyLayer — pme, Apr 09 '20 at 11:30
You definitely can. The thing to keep in mind is that if your custom layer needs a clock the one from the "default" environment will already be available, so you only need to do this yourself if you want to provide a different implementation of the Clock service. — Adam Fraser, Apr 09 '20 at 12:57

'A test is using time, but is not advancing the test clock' in ZIO Test

1 Answers1