Troubleshooting failures

You can add diagnostic information to your tests by using clues and log statements.

You should add information when you write a test, and not just when it fails. This will save you needing to write more code when your test fails later.

This information will only be displayed when a test fails, so will not clutter your test report.

Using `clue` with `expect`

The expect and expect.all statements are used to assert on boolean values. On their own, they don't print any diagnostic information.

You can add information by using the clue function.

val x = List(1, 2, 3)

expect(clue(x.size) > 2)

You can add clues around any variable.

expect(clue(x).size > 2)

You can also nest them.

expect(clue(clue(x).size) > 2)

The clues are displayed when the test fails.

import weaver._

object ExpectWithClueTest extends FunSuite {

  test("This fails, and we can diagnose why") {
    val x = 1
    val y = 2
    expect(clue(x) > clue(y))
  }

  test("This fails, but we don't know why") {
    val x = 1
    val y = 2
    expect(x > y)
  }

  test("This succeeds so nothing is printed") {
    val x = 1
    val y = 0
    expect(clue(x) > clue(y))
  }
}

Example report

ExpectWithClueTest
+ This succeeds so nothing is printed 0ms
- This fails, and we can diagnose why 0ms
- This fails, but we don't know why 0ms

*************FAILURES*************
ExpectWithClueTest
- This fails, and we can diagnose why 0ms
  assertion failed

  expect(clue(x) > clue(y))

  Clues {
    x: Int = 1
    y: Int = 2
  }

  troubleshooting_failures.md#L46
      expect(clue(x) > clue(y))
            ^
- This fails, but we don't know why 0ms
  assertion failed

  expect(x > y)

  Use the `clue` function to troubleshoot

  troubleshooting_failures.md#L52
      expect(x > y)
            ^

Total 3, Failed 2, Passed 1, Ignored 0

Logging information

You can log general information using a lazy logger. Log statements are only printed when a test fails and are displayed along with the test failure.

Access the logger by writing a loggedTest.

import weaver._

object LoggedTests extends SimpleIOSuite {

  case class Response(body: String, status: Int)

  loggedTest("This test fails") { log =>
    val response = Response("this went wrong", 500)
    for {
      _ <- log.info(s"The response body is: ${response.body}")
    } yield expect.eql(200, response.status)
  }

  loggedTest("This test also fails, and has separate logs") { log =>
    val response = Response("this also went wrong", 400)
    for {
      _ <- log.info(s"The response body is: ${response.body}")
    } yield expect.eql(200, response.status)
  }

  loggedTest("This test succeeds, so no logs are printed") { log =>
    val response = Response("OK", 200)
    for {
      _ <- log.info(s"The response body is: ${response.body}")
    } yield expect.eql(200, response.status)
  }
}

Example report

LoggedTests
+ This test succeeds, so no logs are printed 5ms
- This test fails 8ms
- This test also fails, and has separate logs 7ms

*************FAILURES*************
LoggedTests
- This test fails 8ms
  Values not equal:

  in expect.eql(- expected, + found)
  -200
  +500

  troubleshooting_failures.md#L83
      } yield expect.eql(200, response.status)
                        ^

    [INFO] 12:32:09 [troubleshooting_failures.md:82] The response body is: this went wrong
- This test also fails, and has separate logs 7ms
  Values not equal:

  in expect.eql(- expected, + found)
  -200
  +400

  troubleshooting_failures.md#L90
      } yield expect.eql(200, response.status)
                        ^

    [INFO] 12:32:09 [troubleshooting_failures.md:89] The response body is: this also went wrong

Total 3, Failed 2, Passed 1, Ignored 0

Use `log.info` instead of `println`

You should use log statements instead of println statements.

Because weaver runs tests in parallel, it is difficult to pinpoint which test a println statement corresponds to.

Unlike log statements, println statements are always printed, regardless of whether a test succeeds or fails, so can clutter the test output.

Log statements are only printed if a test fails. The logs statements are displayed along with the test failure they correspond to, so it's easy to troubleshoot tests even though they are run in parallel.

Accessing the logger along with shared resources

You can access the logger along with shared resources by using the second argument of the test function.

import weaver._
import cats.effect._

import org.http4s.ember.client._
import org.http4s.client._

object HttpSuite extends IOSuite {

  override type Res = Client[IO]
  override def sharedResource : Resource[IO, Res] =
    EmberClientBuilder.default[IO].build

  // The log is passed as the second argument
  test("This test fails") { (httpClient, log) =>
    for {
      statusCode <- httpClient.get("https://httpbin.org/oops") {
        response => for {
          _ <- log.info(s"Content length: ${response.contentLength}")
        } yield response.status.code
      }
    } yield expect.eql(200, statusCode)
  }
}

Example report

HttpSuite
- This test fails 1s

*************FAILURES*************
HttpSuite
- This test fails 1s
  Values not equal:

  in expect.eql(- expected, + found)
  -200
  +503

  troubleshooting_failures.md#L137
      } yield expect.eql(200, statusCode)
                        ^

    [INFO] 12:32:11 [troubleshooting_failures.md:134] Content length: Some(162)

Total 1, Failed 1, Passed 0, Ignored 0

Displaying the correct source location

Assertions such as expect and expect.eql display their source location when they fail.

If you make assertions in helper functions, you might want to display the source location of the call to the helper.

You can do this by requiring an implicit SourceLocation argument.

import weaver._

object SourceLocationSuite extends FunSuite {

  case class Response(body: String, status: Int)

  test("This test fails") {
    val response = Response("this went wrong", 500)
    expectOk(response) // The failure points here
  }

  test("This test fails with a different source location") {
    val response = Response("this also went wrong", 500)
    expectOk(response) // The other failure points here
  }

  def expectOk(response: Response)(implicit loc: SourceLocation): Expectations = {
     expect.eql(200, response.status) && expect.eql("OK", response.body)
  }
}

Example report

SourceLocationSuite
- This test fails 2ms
- This test fails with a different source location 0ms

*************FAILURES*************
SourceLocationSuite
- This test fails 2ms
 [0] Values not equal:
 [0] 
 [0] in expect.eql(- expected, + found)
 [0] -200
 [0] +500
 [0] 
 [0] troubleshooting_failures.md#L160
 [0]     expectOk(response) // The failure points here
 [0]             ^

 [1] Values not equal:
 [1] 
 [1] in expect.eql(- expected, + found)
 [1] -OK
 [1] +this went wrong
 [1] 
 [1] troubleshooting_failures.md#L160
 [1]     expectOk(response) // The failure points here
 [1]             ^
- This test fails with a different source location 0ms
 [0] Values not equal:
 [0] 
 [0] in expect.eql(- expected, + found)
 [0] -200
 [0] +500
 [0] 
 [0] troubleshooting_failures.md#L165
 [0]     expectOk(response) // The other failure points here
 [0]             ^

 [1] Values not equal:
 [1] 
 [1] in expect.eql(- expected, + found)
 [1] -OK
 [1] +this also went wrong
 [1] 
 [1] troubleshooting_failures.md#L165
 [1]     expectOk(response) // The other failure points here
 [1]             ^

Total 2, Failed 2, Passed 0, Ignored 0

Displaying source locations in CI test runs

Source locations in CI runs are displayed as urls. If you use GitHub Actions, the source code URL is determined automatically.

[info] weaver.framework.test.ExpectationsTests
[error] - should fail 19ms
[error]   Values not equal: (https://github.com/typelevel/weaver-test/tree/4390ba8e91faa6e9ed2e0d112271d9c8e80d7034/modules/framework-cats/shared/src/test/scala/ExpectationsTests.scala#L107)
[error]
[error]   in expect.eql(- expected, + found)
[error]   -1
[error]   +2
[error]
[error]   https://github.com/typelevel/weaver-test/tree/4390ba8e91faa6e9ed2e0d112271d9c8e80d7034/modules/framework-cats/shared/src/test/scala/ExpectationsTests.scala#L107
[error]       expect.eql(1, 2)
[error]                 ^"""

You can display urls in other CI providers using the WEAVER_SOURCE_URL environment variable.

export WEAVER_SOURCE_URL=https://gitlab.com/my-org/my-repo/-/tree/my-branch/

Here are some common provider formats:

Provider	`WEAVER_SOURCE_URL` value
GitHub	`${GITHUB_SERVER_URL}/${GITHUB_REPOSITORY}/tree/${GITHUB_SHA}/` (set by default)
GitLab	`${CI_PROJECT_URL}/-/tree/${CI_COMMIT_SHA}/`

Displaying a trace

If you have a test codebase with many nested helper functions, you may want to display a trace of source locations. You can do this with the traced(here) function.

In the following example, expectOk calls expectStatus and expectOkBody. When the test fails, the source location of both expectStatus and expectOk is displayed.

import weaver._

object TracingSuite extends FunSuite {

  case class Response(body: String, status: Int)

  test("This test fails") {
    val response = Response("this went wrong", 500)
    expectOk(response) // The failure points here first
  }

  def expectOk(response: Response)(implicit loc: SourceLocation): Expectations = {
     expectOkStatus(response)
       .traced(here) // The failure points here third
  }

  def expectOkStatus(response: Response)(implicit loc: SourceLocation): Expectations = {
     expect.eql(200, response.status)
       .traced(here) // The failure points here second
  }

}

Example report

TracingSuite
- This test fails 2ms

*************FAILURES*************
TracingSuite
- This test fails 2ms
  Values not equal:

  in expect.eql(- expected, + found)
  -200
  +500

  troubleshooting_failures.md#L192
      expectOk(response) // The failure points here first
              ^
  troubleshooting_failures.md#L202
         .traced(here) // The failure points here second
                 ^
  troubleshooting_failures.md#L197
         .traced(here) // The failure points here third
                 ^

Total 1, Failed 1, Passed 0, Ignored 0

Troubleshooting failures

Using clue with expect

Example report

Logging information

Example report

Use log.info instead of println

Accessing the logger along with shared resources

Example report

Displaying the correct source location

Example report

Displaying source locations in CI test runs

Displaying a trace

Example report

Using `clue` with `expect`

Use `log.info` instead of `println`