What's Upcoming in Gradle 1.1: Test Logging

Until recently, Gradle wasn’t very forthcoming about what was happening during test execution. The console output was scarce, and the (admittedly nice) HTML report could only be viewed once all tests had completed.

In Gradle 1.1, this is about to change. We are introducing a revamped console logging that keeps you up-to-date on everything that’s going on during test execution.

Old vs. New Console Output --------------------------

Let’s start out by comparing the old and new test output for a typical JUnit test failure. All output shown is from tests for the Spring Integration project, which I’ve sabotaged to throw an exception or two. Note that I’ve abbreviated package names to accommodate the limited page width in our forum. (Incidentally, this might also make a good test logging feature.)

Old:

:spring-integration-twitter:test
Test o.s.i.t.i.MessageSourceTests FAILED
4 tests completed, 1 failure

New:

o.s.i.t.i.MessageSourceTests > testSearchReceivingMessageSourceInit
FAILED
    j.f.AssertionFailedError at MessageSourceTests.java:96
  4 tests completed, 1 failed, 1 skipped

In keeping with Gradle’s tradition, the new test output still defaults to being concise. Nevertheless, it provides the following additional information:

  • The name of the failing test method * The name of the exception that occurred * The test file and line at which the exception occurred

Also, the test summary received a little update in that it now displays the number of skipped tests.

Displaying More Information ---------------------------

What if you need more information? It’s just one line of configuration away:

test {
    testLogging {
        exceptionFormat "full" // default is "short"
    }
}

With this, the output becomes:

o.s.i.t.i.MessageSourceTests > testSearchReceivingMessageSourceInit FAILED
    j.f.AssertionFailedError: null
        at j.f.Assert.fail(Assert.java:47)
        at j.f.Assert.assertTrue(Assert.java:20)
        at j.f.Assert.assertTrue(Assert.java:27)
        at o.s.i.t.i.MessageSourceTests.testSearchReceivingMessageSourceInit(MessageSourceTests.java:96)
  4 tests completed, 1 failed, 1 skipped

Here, the following additional information is shown:

  • The exception message (which happens to be ‘null’ in this case) * The full stack trace

Wait, is this really the full stack trace? Well, almost. By default, Gradle applies a conservative stack trace filter that truncates the stack trace below the first entry point into the test class. In other words, you are saved from all the Gradle and JUnit internals which typically don’t add any value to diagnosing your problem.

Here is the list of currently supported stack trace filters:

  • ‘entryPoint’ shows the entry point into the test class (one line) * ‘truncate’ truncates everything below the entry point into the test class * ‘groovy’ filters Groovy runtime internals, dramatically shortening Groovy stack traces

Stack trace filters can be combined:

test {
    testLogging {
        stackTraceFilters "truncate", "groovy"
    }
}

Moving on, exception causes are shown by default and indented for easier recognition:

o.s.i.t.i.MessageSourceTests > testSearchReceivingMessageSourceInit FAILED
    o.s.i.MessageDeliveryException: Failed to send tweet 'Liking the new Gradle test logging output!'
        at o.s.i.t.i.SearchReceivingMessageSource.<init>(SearchReceivingMessageSource.java:42)
        at o.s.i.t.i.MessageSourceTests.testSearchReceivingMessageSourceInit(MessageSourceTests.java:81)
          Caused by:
        o.s.i.MessageSourceException: Oops! Looks like Twitter is down. Try again shortly.
            at o.s.i.c.IntegrationObjectSupport.onInit(IntegrationObjectSupport.java:113)
            at o.s.i.t.i.AbstractTwitterMessageSource.onInit(AbstractTwitterMessageSource.java:92)
            at o.s.i.t.i.SearchReceivingMessageSource.<init>(SearchReceivingMessageSource.java:40)
            ... 1 more

Further Configuration Options -----------------------------

Interested in test events beyond ‘test failed’?

test {
    testLogging {
        events "started", "passed", "skipped", "failed", "standardOut", "standardError"
    }
}
:spring-integration-twitter:test
o.s.i.t.i.MessageSourceTests > testSearchReceivingMessageSourceInit STARTED
o.s.i.t.i.MessageSourceTests > testSearchReceivingMessageSourceInit STANDARD_OUT
    19:15:12,659
WARN Test worker inbound.SearchReceivingMessageSource:111 -
     SearchReceivingMessageSource has no name. MetadataStore key might not be unique.
  o.s.i.t.i.MessageSourceTests > testSearchReceivingMessageSourceInit FAILED
    j.f.AssertionFailedError at MessageSourceTests.java:96
  o.s.i.t.i.MessageSourceTests > testPollForTweetsNullResults STARTED
o.s.i.t.i.MessageSourceTests > testPollForTweetsNullResults PASSED
o.s.i.t.i.MessageSourceTests > testPollForTweetsThreeResults STARTED
o.s.i.t.i.MessageSourceTests > testPollForTweetsThreeResults PASSED
o.s.i.t.i.MessageSourceTests > demoReceiveSearchResults STARTED
o.s.i.t.i.MessageSourceTests > demoReceiveSearchResults SKIPPED
o.s.i.t.i.MessageSourceTests FAILED
4 tests completed, 1 failed, 1 skipped

Want to see only class-level events?

test {
    testLogging {
        minGranularity 2
        maxGranularity 2
    }
}
o.s.i.t.i.MessageSourceTests STARTED
o.s.i.t.i.MessageSourceTests FAILED
4 tests completed, 1 failed, 1 skipped

Want to see the full exception output, but only when info logging (’–info’) is turned on?

test {
    testLogging {
        info {
            exceptionFormat "full"
        }
    }
}

For full coverage of all configuration options, see the API documentation for TestLogging and TestLoggingContainer. Please note that the test logging feature is currently marked as ‘@Experimental’, which means that its API (and also the resulting console output) may still be subject to change after the 1.1 release.

Viewing the HTML Report -----------------------

I’ve saved one little gem for the end. Previously, in order to view the HTML report, you had to manually open the displayed file path in your browser. In 1.1, the output was slightly tweaked to show a file URL:

* What went wrong:
Execution failed for task ':spring-integration-twitter:test'.
> There were failing tests. See the report at file:///spring-integration/spring-integration-twitter/build/reports/tests/index.html.

Many terminals will recognize this URL automatically. For example, on a Mac the URL can be selected with a right-click, and opening the URL is as easy as CMD+double-click.

Epilogue --------

This concludes my tour of the new test logging feature. You can already try it in a nightly build, or wait for the upcoming Gradle 1.1-rc-1 release. If you have any feedback, please share it right in this forum topic. Enjoy!

Very nice! I’m surprised no one else has chimed in, so let me be the first. These are all great additions that should great improve the testing process.

How do I make test report html be opened automatically from Gradle… This avoids one more click and can help on terminals which does not support links

depending on your OS you can use some simple groovy code to achieve this:

test{
   doLast{
       "open $buildDir/reports/tests/index.html".execute()
   }
}

I like the changes in the test file. Showing index.html instead of the directory, and removing the dot at the end helps a lot.

Jenkins seems to have an issue though. In 1.0, Jenkins replaces the base directory name with a URL, which it puts in the failure email. Clicking on it doesn’t work because of the dot at the end. In 1.1-rc-1, jenkins still replaces the directory, but that leaves a URL like “file://<http://maxdev2:8080/job/max/ws/build/reports/tests/index.html”, which doesn’t work either. Is there a way to tell Gradle to skip the “file://” part for CI servers?

Is this with the Jenkins Gradle Plugin?

It is. I’ve discovered that with the email-ext plugin, you can work around it by using “${PROJECT_URL}/ws/build/reports/tests/index.html” in the email body.

It would still be cool if the Jenkins and its Gradle plugin could do it out of the box though.

Would you mind filing an issue with the Jenkins Gradle Plugin?

No problem. I created https://issues.jenkins-ci.org/browse/JENKINS-14562 to track it. While I was at it, I mentioned that the plugin keeps the “.” at the end of the Gradle 1.0 results.

Thanks!

Is there an option to fail test exceeding time limit ?