Catch2
Catch2 copied to clipboard
Logging macro similar to UNSCOPED_INFO but that doesn't remove it from the buffer
Sometimes I have something similar to the following
#define CATCH_CONFIG_MAIN
#include <catch2/catch.hpp>
#include <spdlog/spdlog.h>
#include <spdlog/sinks/base_sink.h>
class spdlog_catch_sink final : public spdlog::sinks::base_sink<spdlog::details::null_mutex>
{
protected:
void sink_it_(const spdlog::details::log_msg& msg) override
{
spdlog::memory_buf_t formatted;
spdlog::sinks::base_sink<spdlog::details::null_mutex>::formatter_->format(msg, formatted);
UNSCOPED_INFO(fmt::to_string(formatted));
}
void flush_() override {}
};
static bool factorial_called_with_one;
static unsigned int Factorial( unsigned int number ) {
spdlog::info("Factorial called with {}", number);
if(factorial_called_with_one) {
return 0;
}
if(number == 1) {
factorial_called_with_one = true;
}
return number <= 1 ? number : Factorial(number-1)*number;
}
TEST_CASE( "Factorials are computed", "[factorial]" ) {
spdlog::default_logger_raw()->sinks() = { std::make_shared<spdlog_catch_sink>() };
factorial_called_with_one = false;
REQUIRE( Factorial(1) == 1 );
SECTION( "even after calling it with 1" ) {
REQUIRE( Factorial(2) == 2 );
}
}
which outputs this
$ ./catch_test
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
catch_test is a Catch v2.13.7 host application.
Run with -? for options
-------------------------------------------------------------------------------
Factorials are computed
even after calling it with 1
-------------------------------------------------------------------------------
catch_test.cpp:41
...............................................................................
catch_test.cpp:42: FAILED:
REQUIRE( Factorial(2) == 2 )
with expansion:
0 == 2
with message:
[2021-12-27 11:12:35.543] [info] Factorial called with 2
===============================================================================
test cases: 1 | 1 failed
assertions: 3 | 2 passed | 1 failed
So basically I have the logging infrastructure, set to maximum verbose level, report to Catch. I do this because I only want to see the logging output if a test fails, but when it fails I want to have as much logging information as possible. In general, it works fine. But since the output of UNSCOPED_INFO is flushed with every assertion, sometimes I lose useful output when an assertion fails, but a previous one had succeeded.
I could probably handle this by using an event listener instead of UNSCOPED_INFO, handling the buffering myself. But for this use case, it may have been nice to have had a NOT_FLUSHED_UNSCOPED_INFO that is only flushed at the end of the "path" (it's still flushed before starting testing a new path, since that's basically a different test run).
In the given example (which admittedly is forced), the fact that Factorial was called first with 1 is important but not logged.
Given
$ ./catch_test -s
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
catch_test is a Catch v2.13.7 host application.
Run with -? for options
-------------------------------------------------------------------------------
Factorials are computed
-------------------------------------------------------------------------------
catch_test.cpp:34
...............................................................................
catch_test.cpp:39: PASSED:
REQUIRE( Factorial(1) == 1 )
with expansion:
1 == 1
with message:
[2021-12-27 14:32:53.597] [info] Factorial called with 1
-------------------------------------------------------------------------------
Factorials are computed
even after calling it with 1
-------------------------------------------------------------------------------
catch_test.cpp:41
...............................................................................
catch_test.cpp:42: FAILED:
REQUIRE( Factorial(2) == 2 )
with expansion:
0 == 2
with message:
[2021-12-27 14:32:53.597] [info] Factorial called with 2
-------------------------------------------------------------------------------
Factorials are computed
-------------------------------------------------------------------------------
catch_test.cpp:34
...............................................................................
catch_test.cpp:39: PASSED:
REQUIRE( Factorial(1) == 1 )
with expansion:
1 == 1
with message:
[2021-12-27 14:32:53.597] [info] Factorial called with 1
===============================================================================
test cases: 1 | 1 failed
assertions: 3 | 2 passed | 1 failed
maybe another solution would be to increase the output when an assertion fails?
I would probably be OK with having
$ ./catch_test
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
catch_test is a Catch v2.13.7 host application.
Run with -? for options
-------------------------------------------------------------------------------
Factorials are computed
even after calling it with 1
-------------------------------------------------------------------------------
catch_test.cpp:41
...............................................................................
catch_test.cpp:42: FAILED:
REQUIRE( Factorial(2) == 2 )
with expansion:
0 == 2
with message:
[2021-12-27 14:32:53.597] [info] Factorial called with 2
-------------------------------------------------------------------------------
Factorials are computed
-------------------------------------------------------------------------------
catch_test.cpp:34
...............................................................................
catch_test.cpp:39: PASSED:
REQUIRE( Factorial(1) == 1 )
with expansion:
1 == 1
with message:
[2021-12-27 14:32:53.597] [info] Factorial called with 1
===============================================================================
test cases: 1 | 1 failed
assertions: 3 | 2 passed | 1 failed
i.e. when the assertion fails getting the output of the whole path/branch.