Poor performance of check library, when using assertions

I am using check to write some simple unit tests for my C library. I am measuring a huge performance loss when using ck_assert* functions from check. Normal asserts work fine.

For example consider the following test case:

START_TEST(julian_gregorian)
{
    uint32_t jd = 0;
    uint32_t out_jd = 0;
    uint32_t in_jd;
    int16_t gyi;
    uint8_t gmi;
    uint16_t gdi;
    int16_t gyo;
    uint8_t gmo;
    uint16_t gdo;
    for (jd = 0; jd < 2488069; jd++)
    {
        test_gregorian_calendar(ctx, jd,
            &gyi, &gmi, &gdi,
            &gyo, &gmo, &gdo);
        ck_assert(gyi == gyo); // <============== very slow
        ck_assert(gmi == gmo);
        ck_assert(gdi == gdo);
    }
}
END_TEST

This takes more than a minute to complete:

2: Test timeout computed to be: 10000000
2: Running suite(s): Calendar Arithmetic
2: 100%: Checks: 2, Failures: 0, Errors: 0
1/1 Test #2: Julian ...........................   Passed   87.94 sec

When I change back to assert I get less than a second:

2: Test timeout computed to be: 10000000
2: Running suite(s): Calendar Arithmetic
2: 100%: Checks: 2, Failures: 0, Errors: 0
1/1 Test #2: Julian ...........................   Passed    0.61 sec

I can not see what is so slow about ck_assert. It seems like it does not do anything special. It's a macro that calls another one with parameters:

#define ck_assert(expr) ck_assert_msg(expr, NULL)

and then just runs the expression:

#define ck_assert_msg(expr, ...) \
  (expr) ? \
     _mark_point(__FILE__, __LINE__) : \
     _ck_assert_failed(__FILE__, __LINE__, "Assertion '"#expr"' failed" , ## __VA_ARGS__)

and those two (_mark_point and assert fail message) are functions from the shared library of check. I assume nothing much is going on there, just formatting and logging maybe.

I don't see why it has to be so slow. I like to use more features from check if I can help the performance issue.

those two (_mark_point and assert fail message) are functions from the shared library of check. I assume nothing much is going on there, just formatting and logging maybe.

This is not a prudent assumption, and there is no basis for it.

Brief inspection of the sources shows that _mark_point calls send_loc_info, which calls strdup (thus allocating memory), free, and ppack, and ppack locks a mutex, calls fwrite and fflush, and unlocks the mutex, along with other work.

So, it is not surprising that calling it millions of times takes time.

(The reason for locking a mutex is unclear, as fwrite is part of the C standard library streaming routines, which include their own locks.)