Search code examples
clinuxunit-testingtime

Measuring the time a child process takes to exit in C


I am trying to create a very minimal unit testing header-only library in C.

I have a very basic macro setup called RUN_TEST_CASE which forks the process and executes a given test case, which is just a function. I wanted to fork to covert the cases where the test doesn't exit correctly (with a SIGSEGV for example). I want to print out the time it took the test case to run, preferably in seconds.

This is the code I have so far -

#include <stdio.h>
#include <unistd.h>
#include <wait.h>
#include <sys/types.h>
#include <time.h>

#define __MINTEST_SAFE_BLOCK(block) \
    do                              \
    {                               \
        block                       \
    } while (0)

#define TEST_CASE(test) static void test(void)

#define TEST_SUITE(suite) static void suite(void)

#define __RUN_TEST_CASE(test, caller) __MINTEST_SAFE_BLOCK(                                               \
    pid_t pid;                                                                                            \
    int status;                                                                                           \
    clock_t begin;                                                                                        \
    clock_t end;                                                                                          \
    double time_spent;                                                                                    \
                                                                                                          \
    begin = clock();                                                                                      \
    pid = fork();                                                                                         \
    switch (pid) {                                                                                        \
        case -1:                                                                                          \
            perror("fork");                                                                               \
            break;                                                                                        \
        case 0:                                                                                           \
            test();                                                                                       \
            break;                                                                                        \
        default:                                                                                          \
            waitpid(pid, &status, 0);                                                                     \
            end = clock();                                                                                \
            time_spent = (end - begin);                                                                   \
            if (WIFEXITED(status))                                                                        \
            {                                                                                             \
                printf("%s:%s passed after %fms [%d]\n", caller, #test, time_spent, WEXITSTATUS(status)); \
            }                                                                                             \
            else if (WIFSIGNALED(status))                                                                 \
            {                                                                                             \
                printf("%s:%s failed after %fms [%d]\n", caller, #test, time_spent, WTERMSIG(status));    \
            }                                                                                             \
            break;                                                                                        \
    })

#define RUN_TEST_CASE(test) __RUN_TEST_CASE(test, __func__)

#define RUN_TEST_SUITE(suite) suite()

I am testing these macros with the following C code -

#include "mintest.h"

TEST_CASE(test_something) {
    printf("In test\n");
    sleep(2);
    *(volatile int*)NULL;
};

TEST_SUITE(test_suite) {
    RUN_TEST_CASE(test_something);
};

int main(void) {
    RUN_TEST_SUITE(test_suite);
    return 0;
}

I am expecting to see printed out that the test Failed and took about 2 seconds, but I am getting very inconsistent results -

In test
test_suite:test_something failed after 574.000000ms [11]

In test
test_suite:test_something failed after 462.000000ms [11]

In test
test_suite:test_something failed after 689.000000ms [11]

Is there something I'm doing wrong? Perhaps I have a wrong understanding of what waitpid() does?


Solution

  • clock() returns processor time (not elapsed time) in clock-ticks, not milliseconds. You need to divide by (double)CLOCKS_PER_SEC to convert to seconds, but that is probably still not what you want as it is just the time spent in the parent, and doesn't including any time spent in wait.

    You can get a more useful number by using clock_gettime instead.


    After running the test in the child, it should call exit (or _exit); otherwise it could continue running the testing code (which means it will run additional copies of subsequent tests in grandchildren and generally blow up.) In your specific case, it won't happen as the testcase is failing with a SEGV, but other tests that pass could have this problem.