catchorg / catchorg/Catch2

Logging macro similar to UNSCOPED_INFO but that doesn't remove it from the buffer

Open
#2,341 1 comment 3 reactions 0 assignees View on GitHub
Dominant language
C++
Stars
21.5k
Forks
3.5k
Avg merge
3d 16h
Merged PRs (30d)
2

Description

Sometimes I have something similar to the following

```
#define CATCH_CONFIG_MAIN
#include
#include
#include

class spdlog_catch_sink final : public spdlog::sinks::base_sink
{
protected:
void sink_it_(const spdlog::details::log_msg& msg) override
{
spdlog::memory_buf_t formatted;
spdlog::sinks::base_sink::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() };

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.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.