Can I get log output only for failures with boost unit tests

Question

I have some logging in my application (it happens to be log4cxx but I am flexible on that), and I have some unit tests using the boost unit test framework. When my unit tests run, I get lots of log output, from both the passing and failing tests (not just boost assertions logged, but my own application code's debug logging too). I would like to get the unit test framework to throw away logs during tests that pass, and output logs from tests that fail (I grew to appreciate this behaviour while using python/nose).

Is there some standard way of doing this with the boost unit test framework? If not, are there some start of test/end of test hooks that I could use to buffer my logs and conditionally output them to implement this behaviour myself?

Poss

Boost.Test does not intercept any log stream such as std::cout or std::cerr but this can be a feature request I may consider (see project's github). This would mean that your code is logging to one of those streams. – Gurnard

Answer 1

There are start of test and end of test hooks that you can use for this purpose. To set up these hooks you need to define a subclass of boost::unit_test::test_observer, create an instance of the class that will persist throughout the entire test (either a static global object or a BOOST_TEST_GLOBAL_FIXTURE), and then pass the class to boost::unit_test::framework::register_observer.

The method to override with a start of test hook is test_unit_start, and the method to override with an end of test hook is test_unit_finish. However, these hooks fire both for test suites as well as individual test cases, which may be an issue depending on how the hooks are set up. The test_unit_finish hook also doesn't explicitly tell you whether a given test actually passed, and there doesn't seem to be one clear and obvious way to get that information. There is a boost::unit_test::results_collector singleton, which has a results() method, and if you pass it the test_unit_id of the test unit provided to test_unit_finish, you get a test_results object that has a passed() method. I can't really see a way to get the test_unit_id that is clearly part of the public API -- you can just directly access the p_id member, but that could always change in a future boost version. You could also manually track whether each test is passing or failing using the assertion_result, exception_caught, test_unit_aborted, and test_unit_timed_out hooks from the test_observer subclass (assertion_result indicates a failure of the current test whenever its argument is false and every other hook indicates a failure if it is called at all).

Detonation

Answer 2

According to the Boost.Test documentation, run your test executable with --log_level=error. This will catch only failing test cases.

I checked that it works using a BOOST_CHECK(false) on an otherwise correctly running project with a few thousand unit tests.

Running with --log_level=all gives the result of all assertions. I checked that by piping it to wc -l that the number of lines in the log is exactly the same as the number of assertions in the tests (which number is also reported by --report_level=detailed). You could of course also grep the log for the strings error or failed.

Weig

That controls the logs from boost itself, but doesn't help me control the debug logs from the application itself – Poss

@Poss then I don't quite follow: what do you mean with "I get lot of log output from the tests"? Where inside your program are you catching them? You could use std::regex on "failed" or "error" for them and drop them as they come buy. – Weig

My code does all kinds of debug logging. What I would like to do is have it all buffered up, and then if a test fails, output it, and if it passes, throw it away. When I say "the tests" I don't just mean boost asserts etc, I mean all the code that's running when I run a test. It's OK if the answer is "no, boost unit tests doesn't provide hooks for that" – Poss

@Poss I can't easily test it, but did you actually try my suggestion of the runtime parameter? The documentation specifically says: "The active log level works namely as threshold, not as selector. For the given active log level threshold, all test log entries with "importance" higher than threshold are enabled and all test log entries with "importance" below threshold are disabled." So you shouldn't see anything except errors when running with --log_level=error. They won't even be generated. – Weig

@Poss I'm still interested to get this to work, can you give me a code example to show where exactly you are catching the errors? – Weig

I think there is some confusion about logs from e.g. BOOST_TEST_MESSAGE (which --log_level may control), and logging from elsewhere in my application (e.g. if something is using log4cxx). Setting --log_level doesn't have any effect on the second type of log. – Poss

@Poss I don't think Boost.Test can filter log messages from other sources. You probably should filter that from your logging library. If log4cxx cannot do that, you could try Boost.Log which is about to be rleased in Boost 1.54.0. If all else fails, you could try the Boost mailinglist where the Boost.Test author usually responds to such questions (though he's also on SO). – Weig