INFO and SCOPED_INFO behaviours (and recent changes)

[Phil Nash]

I have recently committed to changes to Integration that slightly change the semantics of the INFO and SCOPED_INFO macros. These changes where in response to an Issue ticket that had been raised due to a regression in their previous behaviours - but a discussion sprang up there that I felt would be best moved over here.

To summarise:

The new behaviour (integration only, at time of writing) is:

Messages logged with both INFO and SCOPED_INFO are reset at the next assertions, the end of a section or the end of a test case. Additionally SCOPED_INFO messages are reset at the end of the scope in which they were declared.

All messages in effect at the next assertion are passed along with the assertion results to the active reporter. If the reporter is only logging successful results (e.g. the default behaviour for the console reporter) then those messages will only be visible if the assertion fails.

Previously, the messages where only passed to an reporter if the assertion failed - and were not reset otherwise.

[Wichert Akkerman]

I think the current naming is causing some confusion. There are seem to be three different types of messages:

• SCOPED_INFO: conditional messages which are only output if they are followed by a failing test in the same block
• INFO: conditional messages which are only output if the are followed by a failing test in the same section
• WARN: unconditional messages which are always generated

These rules mean that it is easy to write code which will never output anything. For example:

  SECTION("log test", "") {
      {
          MyFixture fixture;
          CHECK(true==false);
          SCOPED_INFO("Message one");
      }
      CHECK(true==false);
      INFO("Message two");
  }

Since SCOPED_INFO is not followed by a test in its block, and the INFO statement is not followed by a test in the same section they will never do anything. I think that behaviour is unexpected. I certainly was not expecting it even though I've been using CATCH for a while now.

In addition some reporters can change the rules a bit: the junit reporter for example will always output messages as specified by the junit standard, and using the -s parameter will also cause all warning macros to generate output. You can also use std::cerr and std::cout manually to output messages, but due to buffering that output will appear misplaced amongst the CATCH-generated messages which makes them effectively unusable. As a user I would like to be able to output messages unconditionally of the outcome of a test. An example: I have a couple of tests which run sanity checks on generated data files and I find it useful to have the test runner output how many data entries were checked along with some statistics. This is currently doable by using WARN, but the name is a bit misleading since this type of output is not a warning.

Having said all that I am not sure what the best way to fix this is. One option is to change SCOPED_INFO to DEBUG and document that the log level dictates when messages are output. This makes behaviour match standard logging frameworks. Another option is to do a more radical renaming to something like LOG, LOG_ON_SECTION_FAIL and LOG_ON_LOCAL_FAIL. That will result in a wall of capslock in your source though. That still means it will be easy for people to write log statements that will never trigger; I'm not sure how to prevent that.

Wichert.

[Pavel Toumanov]

I'm just starting to use Catch which I find just amazing. I still may be misunderstanding some background behind; but, having INFO to behave like SCOPED_INFO looks quite misleading to me. I believe that conditional logging feature that INFO provides is pretty useful because it lets to be verbose without burden of having to analyse a lot of output when nothing is broken. In fact, I've been using it enough to start missing finer-grained control of message scoping. So I did a patch to re-introduce the deprecated behaviour and added one more level of scoping, resulting in the following 3 levels:

 - C++ scope related info (SCOPED_INFO/LOCAL_CAPTURE, can be probably named LOCAL_INFO/LOCAL_CAPTURE)

 - current SECTION related info (SECTION_INFO/SECTION_CAPTURE)

 - global TEST_CASE related info (INFO/CAPTURE)

Could you please clarify why it is considered deprecated? Is there a chance of bringing this functionality back into upstream? I see a perfectly valid uses for all of those.

Can this be re-introduced under a different name like PROVIDE_DETAIL or ATTACH_INFO? I would love to submit my patch should you be interested. 

Thanks,

Pavel

[Pavel Toumanov]

I would like to elaborate why I see global TEST_CASE scoped INFO an important thing to have. I was thinking about possibility to use these macros beyond unit tests, i.e. in underlying code being tested. When building the code for tests it would conditionally include "catch.h" and INFO/CAPTURE statements would be providing contextual info on internal state just in case of test case failure. Then, when building for production these statements can be turned into no-ops (or possibly to debug-level logging). Consider the following sample:

//production.cpp

#if BUILDING_TESTS

#include "catch.hpp"
#else

#include "catch-nop.hpp"
#endif

bool funcionBeingTested()  {
    //do smth.

    CAPTURE(internal_state)

    //do smth else

}

//production_test.cpp

TEST_CASE("test that function") {

    REQUIRE(funcionBeingTested())

}