Lots of assertions (e.g. in loops) are slow

[scrossuk]

If I have a test like the following:

CustomArrayClass<int> array;

const size_t element_count = 64*1024*1024;

for (size_t i = 0; i < element_count; i++)
{
    CHECK(array.size() == i);
    array.push_back(42);
}

CHECK(array.size() == element_count);

for (size_t i = 0; i < element_count; i++)
{
    CHECK(array[i] == 42);
}

The problem is the CHECK asserts in the loops are very slow, which appears to be because the values are being converted into strings each time.

It seems like the above is not the best practice with Catch (?), so could you suggest how a test like this should be written?

[refi64]

Hmm...this makes me wonder...

What if Catch used type erasure to store the lhs and rhs without converting it to a string? Then it can convert it if it actually needs to, not at every test case.

[ecorm]

For very long loops, give a single boolean expression to CATCH, instead of an A == B expression:

for (size_t i = 0; i < element_count; i++)
{
    CHECK( (array.size() == i) );
    array.push_back(42);
}

The extra set of parentheses will make array.size() == i appear as a single boolean expression. Of course, if the assertion fails, you will lose the nice textual information on the LHS and RHS values. The INFO and FAIL macros can be useful in obtaining more diagnostic information on a failure.

[refi64]

@SCross99 Can you try out #562?

[scrossuk]

Thanks for making these changes; the following has some timing figures that hopefully make sense.

Here's a simple example:

#include <vector>

#define CATCH_CONFIG_MAIN  // This tells Catch to provide a main() - only do this in one cpp file
#include "catch.hpp"

TEST_CASE("Example Test", "[tag]") {
    std::vector<int> array;

    const size_t element_count = 1024*1024;
    array.reserve(element_count);

    for (size_t i = 0; i < element_count; i++)
    {
        CHECK(array.size() == i);
        array.push_back(42);
    }

    CHECK(array.size() == element_count);
}

I've reduced the number of iterations 64 times from the original example to make the timing more feasible.

Building with:

$ g++ -o test_example -O3 test_example.cpp

With the unmodified Catch:

$ time ./test_example 
===============================================================================
All tests passed (1048577 assertions in 1 test case)


real    0m7.171s
user    0m7.090s
sys 0m0.008s

With the modified Catch:

$ time ./test_example 
===============================================================================
All tests passed (1048577 assertions in 1 test case)


real    0m6.959s
user    0m6.944s
sys 0m0.008s

By adding extra parentheses to assertion with unmodified Catch:

$ time ./test_example 
===============================================================================
All tests passed (1048577 assertions in 1 test case)


real    0m2.560s
user    0m2.550s
sys 0m0.000s

If the assertion in the loop is removed entirely:

$ time ./test_example 
===============================================================================
All tests passed (1 assertion in 1 test case)


real    0m0.010s
user    0m0.005s
sys 0m0.008s

Given that I'd like to do 64 times the number of comparisons, these timing numbers are too large for either a normal EXPECT or extra parentheses to work. So far I've been using:

#include <vector>

#define CATCH_CONFIG_MAIN  // This tells Catch to provide a main() - only do this in one cpp file
#include "catch.hpp"

TEST_CASE("Example Test", "[tag]") {
    std::vector<int> array;

    const size_t element_count = 64*1024*1024;
    array.reserve(element_count);

    for (size_t i = 0; i < element_count; i++)
    {
        if (array.size() != i) { CHECK(array.size() == i); }
        array.push_back(42);
    }

    CHECK(array.size() == element_count);
}

This gives (note that I'm now building without optimisation and I increased the iterations back to the original 64*1024*1024):

$ g++ -o test_example test_example.cpp 
$ time ./test_example 
===============================================================================
All tests passed (1 assertion in 1 test case)


real    0m2.815s
user    0m2.723s
sys 0m0.080s

This is a reasonably viable figure, though it does show that performing this many comparisons is bound to be slow anyway. Of course, it's a lot faster if I re-enable optimisation:

$ g++ -o test_example -O3 test_example.cpp 
$ time ./test_example 
===============================================================================
All tests passed (1 assertion in 1 test case)


real    0m0.483s
user    0m0.341s
sys 0m0.139s

[ecorm]

Do you really need to check all 64*1024*1024 permutations? Couldn't you just check corner cases, with a few spot checks in between? You might also consider some kind of mathematical proof by induction.

[scrossuk]

Couldn't you just check corner cases, with a few spot checks in between?

Yeah, I think this is the best solution.

[RossBencina]

@SCross99 This ticket seems to be about a performance issue. How about renaming this ticket "Lots of assertions (e.g. in loops) are slow"

[RossBencina]

@kirbyfan64 you got my attention with the claimed performance increase. Lazy stringifying makes sense to me. Travis CI seems to be failing on the current PR. What are your plans for the patch? I'd be interested in helping you test and improve it if you plan to keep working on it.

Lazy stringifying aside, I noticed a couple of potential perf issues with the current master:

• ExprComponents::op could be a const char *, and op comparisons could be reworked to always use pointer comparisons rather than string comparisons.
• C++11 versions of setLhs and setRhs could tale string parameter by r-value reference and move into ExpComponents::lhs, rhs, instead of copying.

[refi64]

I just haven't gotten a chance to fix the failures yet. I'll hopefully do it today or tomorrow.

[RossBencina]

The patch by @kirbyfan64 takes the approach of moving a lot of string conversion into one place, and then avoiding generating strings unless needed. An alternative approach is to improve string handling.

There are numerous opportunities to improve string handling performance in Catch. For example, static file names don't need to be std::string, and string concatenation with operator+ is slow with multiple operands.

Here is a rough-cut of some improvements:

https://github.com/philsquared/Catch/compare/master...RossBencina:rb-master-optimized?expand=1

I get roughly 50% of the performance improvement given by @kirbyfan64's patch. Combining the patches is possible, but since @kirbyfan64's disables most string generation, it disables most of the optimizations in my patch, so there is no aggregate benefit unless some strings will be generated.

I likely won't submit this as a PR until Phil merges some of the smaller dependent changes. In my view, much of this improvement should be done irrespective of the status of the lazily stringify patch.

[horenmar]

#772 is halfway through to being on master, which helps a lot. I am going to open a new meta issue ( #781 ) to keep track of possible performance improvements, but I am closing this one in the meantime.