source: branches/gcc/UNIT_TESTER/UnitTester.cxx

Last change on this file was 19810, checked in by westram, 3 weeks ago
File size: 21.9 KB
Line 
1// ================================================================ //
2//                                                                  //
3//   File      : UnitTester.cxx                                     //
4//   Purpose   :                                                    //
5//                                                                  //
6//   Coded by Ralf Westram (coder@reallysoft.de) in February 2010   //
7//   Institute of Microbiology (Technical University Munich)        //
8//   http://www.arb-home.de/                                        //
9//                                                                  //
10// ================================================================ //
11
12#include "UnitTester.hxx"
13
14#include <cstdarg>
15#include <cstdlib>
16#include <cstdio>
17#include <cstring>
18#include <cerrno>
19#include <climits>
20
21#include <sys/time.h>
22#include <sys/stat.h>
23
24#include <arb_simple_assert.h>
25#include <arb_backtrace.h>
26#include <arb_pathlen.h>
27#include <arb_sleep.h>
28
29#include <test_unit.h>
30#include <ut_valgrinded.h>
31#include <valgrind.h>
32
33#include <SuppressOutput.h>
34
35#include <SigHandler.h>
36#include <setjmp.h>
37#include <unistd.h>
38#include <string>
39#include <exception>
40#include <signal.h>
41
42#include <mod_rlimit.h>
43#include "../SOURCE_TOOLS/arb_main.h"
44
45#define ut_assert(cond) arb_assert(cond)
46
47#if defined(DEBUG)
48# if defined(DEVEL_RALF)
49
50// whether EXPECT_VALID_TEST_LOCATION works or not seems to depend on how well compiler version and system match.
51// now works with gcc 7.3 on my current development machine.
52#  define EXPECT_VALID_TEST_LOCATION
53
54# endif
55#endif
56
57using namespace std;
58
59// --------------------------------------------------------------------------------
60
61struct Globals : virtual Noncopyable {
62    bool        inside_test;
63    bool        running_on_valgrind;
64    char       *runDir;
65    pid_t       pid;
66    const char *libname;
67
68    Globals()
69        : inside_test(false),
70          runDir(NULp),
71          pid(getpid()),
72          libname(NULp)
73    {
74        running_on_valgrind = (RUNNING_ON_VALGRIND>0);
75    }
76    ~Globals() {
77        free(runDir);
78    }
79
80    inline void setup_test_precondition() {
81        TEST_EXPECT_ZERO_OR_SHOW_ERRNO(chdir(runDir));
82    }
83    inline void setup_test_postcondition() {
84        TEST_ANNOTATE(NULp);
85    }
86};
87
88static Globals GLOBAL;
89
90// --------------------------------------------------------------------------------
91// #define TRACE_PREFIX "UnitTester:0: "
92#define TRACE_PREFIX "UnitTester: "
93
94__ATTR__FORMAT(1) static void trace(const char *format, ...) {
95    va_list parg;
96
97    fflush(stdout);
98    fflush(stderr);
99
100    fputs(TRACE_PREFIX, stderr);
101    va_start(parg, format);
102    vfprintf(stderr, format, parg);
103    va_end(parg);
104    fputc('\n', stderr);
105    fflush(stderr);
106}
107
108// --------------------------------------------------------------------------------
109
110inline const char *get_readable_result(UnitTestResult result) {
111    const char *readable = NULp;
112    switch (result) {
113        case TEST_OK:                   readable = "OK"; break;
114        case TEST_TRAPPED:              readable = "TRAPPED"; break;
115        case TEST_FAILED_POSTCONDITION: readable = "VIOLATED"; break;
116        case TEST_INTERRUPTED:          readable = "INTERRUPTED"; break;
117        case TEST_THREW:                readable = "THREW"; break;
118        case TEST_INVALID:              readable = "INVALID"; break;
119        case TEST_LACKS_LOCATION:       readable = "LACKS_LOCATION"; break;
120        case TEST_UNKNOWN_RESULT:       readable = "{unknown}"; break;
121    }
122
123    ut_assert(readable);
124    return readable;
125}
126
127
128// @@@ eliminate TEST_PUBLISH workaround from overall ARB!
129
130// --------------------------------------------------------------------------------
131
132static jmp_buf UNITTEST_return_after_segv;
133static bool    terminate_was_called = false;
134
135enum TrapCode {
136    TRAP_UNEXPECTED = 668,
137    TRAP_SEGV,
138    TRAP_INT,
139    TRAP_TERM,
140};
141
142__ATTR__NORETURN static void UNITTEST_sigsegv_handler(int sig) {
143    if (GLOBAL.inside_test) {
144        int  trap_code;
145        const char *backtrace_cause = NULp;
146        switch (sig) {
147            case SIGSEGV: {
148                trap_code = TRAP_SEGV;
149
150                arb_test::GlobalTestData& test_data = arb_test::test_data();
151                if (!test_data.assertion_failed) { // not caused by assertion
152                    backtrace_cause = "Caught SIGSEGV not caused by assertion";
153                }
154                break;
155            }
156            case SIGINT:
157                trap_code = TRAP_INT;
158                backtrace_cause = "Caught SIGINT (deadlock in test function?)";
159                break;
160
161            case SIGTERM:
162                trap_code = TRAP_TERM;
163                if (terminate_was_called) {
164                    backtrace_cause = "Caught SIGTERM, cause std::terminate() has been called in test-code (might be an invalid throw)";
165                }
166                else {
167                    backtrace_cause = "Caught SIGTERM (deadlock in uninterruptable test function?)";
168                }
169                break;
170
171            default:
172                trap_code = TRAP_UNEXPECTED;
173                test_assert(0, true);
174                break;
175        }
176        if (backtrace_cause) demangle_backtrace(BackTraceInfo(0), stderr, backtrace_cause);
177        siglongjmp(UNITTEST_return_after_segv, trap_code); // suppress signal
178    }
179
180    const char *signame = NULp;
181    switch (sig) {
182        case SIGSEGV: signame = "SEGV"; break;
183        case SIGINT: signame  = "INT"; break;
184        case SIGTERM: signame = "TERM"; break;
185    }
186
187    fputs("[UnitTester catched unexpected signal ", stderr);
188    if (signame) fputs(signame, stderr); else fprintf(stderr, "%i", sig);
189    fputs("]\n", stderr);
190    BackTraceInfo(0).dump(stderr, "Unexpected signal (NOT raised in test-code)");
191    exit(EXIT_FAILURE);
192}
193
194#define SECOND 1000000
195
196static void terminate_called() {
197    // example-test triggering call of terminate_called(): ../CORE/arb_signal.cxx@TEST_throw_during_throw
198    terminate_was_called = true;
199    raise(SIGTERM);
200    // GBK_dump_backtrace(stdout, "just raised SIGTERM - wtf am i doing here"); fflush(stdout);
201}
202
203static UnitTestResult execute_guarded_ClientCode(UnitTest_function fun, long *duration_usec) {
204    terminate_handler old_terminate = std::set_terminate(terminate_called);
205
206    SigHandler old_int_handler  = INSTALL_SIGHANDLER(SIGINT,  UNITTEST_sigsegv_handler, "execute_guarded");
207    SigHandler old_term_handler = INSTALL_SIGHANDLER(SIGTERM, UNITTEST_sigsegv_handler, "execute_guarded");
208    SigHandler old_segv_handler = INSTALL_SIGHANDLER(SIGSEGV, UNITTEST_sigsegv_handler, "execute_guarded");
209
210    // ----------------------------------------
211    // start of critical section
212    // (need volatile for modified local auto variables, see man longjump)
213    volatile timeval        t1;
214    volatile UnitTestResult result  = TEST_OK;
215    volatile int            trapped = sigsetjmp(UNITTEST_return_after_segv, 1);
216
217    if (trapped) {
218        switch (trapped) {
219            case TRAP_UNEXPECTED: ut_assert(0); // fall-through
220            case TRAP_SEGV: result = TEST_TRAPPED; break;
221
222            case TRAP_INT:
223            case TRAP_TERM: result = TEST_INTERRUPTED; break;
224        }
225    }
226    else { // normal execution
227        GLOBAL.inside_test = true;
228
229        gettimeofday((timeval*)&t1, NULp);
230
231        arb_test::test_data().assertion_failed = false;
232        arb_test::test_data().running_test = true;
233
234        // Note: fun() may do several ugly things, e.g.
235        // - segfault                           (handled)
236        // - never return                       (handled by caller)
237        // - exit() or abort()                  (std::terminate is handled, direct call to abort is not)
238        // - throw an exception                 (catched by caller of execute_guarded_ClientCode)
239        // - change working dir                 (should always be reset before i get called)
240
241        fun();
242
243        // sleepms(10000); // simulate a deadlock
244    }
245    // end of critical section
246    // ----------------------------------------
247
248    timeval t2;
249    gettimeofday(&t2, NULp);
250    *duration_usec = (t2.tv_sec - t1.tv_sec) * SECOND + (t2.tv_usec - t1.tv_usec);
251
252    GLOBAL.inside_test = false;
253
254    UNINSTALL_SIGHANDLER(SIGSEGV, UNITTEST_sigsegv_handler, old_segv_handler, "execute_guarded");
255    UNINSTALL_SIGHANDLER(SIGTERM, UNITTEST_sigsegv_handler, old_term_handler, "execute_guarded");
256    UNINSTALL_SIGHANDLER(SIGINT,  UNITTEST_sigsegv_handler, old_int_handler,  "execute_guarded");
257
258    terminate_handler handler = std::set_terminate(old_terminate);
259    if (handler != terminate_called) {
260        fputs("Error: test-code has modified std::terminate (this is invalid)\n", stderr);
261        fflush(stderr);
262        result = TEST_INVALID;
263    }
264
265    return result;
266}
267
268inline bool kill_verbose(pid_t pid, int sig, const char *signame) {
269    int result = kill(pid, sig);
270    if (result != 0) {
271        fprintf(stderr, "Failed to send %s to test (%s)\n", signame, strerror(errno));
272        fflush(stderr);
273    }
274    return result == 0;
275}
276
277class Flag {
278    string flagname;
279
280public:
281    Flag(const string& flagname_) : flagname(flagname_) {}
282
283    bool is_up() const { struct stat stt; return stat(flagname.c_str(), &stt) == 0 && S_ISREG(stt.st_mode); }
284    void raise() {
285        fprintf(stderr, "Raising flag '%s'\n", flagname.c_str()); fflush(stderr);
286        ut_assert(!is_up());
287        FILE *fp = fopen(flagname.c_str(), "w");
288        fclose(fp);
289    }
290    void lower() {
291        fprintf(stderr, "Lowering flag '%s'\n", flagname.c_str()); fflush(stderr);
292        ut_assert(is_up());
293        TEST_EXPECT_ZERO_OR_SHOW_ERRNO(unlink(flagname.c_str()));
294    }
295
296    void lower_if_up() { if (is_up()) lower(); }
297};
298
299inline Flag getLocalFlag(const char *flagname) {
300    string localname  = string(GLOBAL.runDir)+"/../flags/"+flagname+'.'+GLOBAL.libname;
301    return Flag(localname);
302}
303
304static bool flag_callback(arb_test::FlagAction action, const char *name) {
305    using namespace arb_test;
306
307    Flag flag   = getLocalFlag(name);
308    bool result = true;
309
310    switch (action) {
311        case FLAG_RAISE:
312            if (!flag.is_up()) flag.raise();
313            break;
314        case FLAG_IS_RAISED:
315            result = flag.is_up();
316            break;
317    }
318
319    return result;
320}
321
322inline bool been_inside_environment() {
323    return getLocalFlag(ANY_SETUP).is_up() || arb_test::test_data().entered_mutex_loop;
324}
325inline bool did_valgrinded_syscall() {
326    return seen_valgrinded_call();
327}
328inline void reset_test_local_flags() {
329    getLocalFlag(ANY_SETUP).lower_if_up();
330}
331
332void sleepms(long ms) {
333    long seconds = ms/1000;
334    long rest_ms = ms - seconds*1000;
335
336    if (seconds) ARB_sleep(seconds, SEC);
337    ARB_sleep(rest_ms, MS);
338}
339
340#if (DEADLOCKGUARD == 1)
341__ATTR__NORETURN static void deadlockguard(long max_allowed_duration_ms, bool detect_environment_calls) {
342    // this function is completely incompatible with debuggers
343    sleepms(max_allowed_duration_ms);
344
345    if (detect_environment_calls && been_inside_environment()) {
346        fprintf(stderr, "[test_environment has been called. Added %li ms tolerance]\n", MAX_EXEC_MS_ENV);
347        fflush(stderr);
348        sleepms(MAX_EXEC_MS_ENV);
349        max_allowed_duration_ms += MAX_EXEC_MS_ENV;
350    }
351
352    if (did_valgrinded_syscall()) {
353        const long additional    = max_allowed_duration_ms*3 + MAX_EXEC_MS_VGSYS;
354        fprintf(stderr, "[external calls are running valgrinded. Added %li ms tolerance]\n", additional);
355        fflush(stderr);
356        sleepms(additional);
357        max_allowed_duration_ms += additional;
358    }
359
360    const int aBIT = 50; // 50 milliseconds
361
362    fprintf(stderr,
363            "[deadlockguard woke up after %li ms]\n"
364            "[interrupting possibly deadlocked test]\n",
365            max_allowed_duration_ms); fflush(stderr);
366    kill_verbose(GLOBAL.pid, SIGINT, "SIGINT");
367    sleepms(aBIT); // give parent a chance to kill me
368
369    fprintf(stderr, "[test still running -> terminate]\n"); fflush(stderr);
370    kill_verbose(GLOBAL.pid, SIGTERM, "SIGTERM");
371    sleepms(aBIT); // give parent a chance to kill me
372
373    fprintf(stderr, "[still running -> kill]\n"); fflush(stderr);
374    kill_verbose(GLOBAL.pid, SIGKILL, "SIGKILL"); // commit suicide
375    // parent had his chance
376    fprintf(stderr, "[still alive after suicide -> perplexed]\n"); fflush(stderr);
377    exit(EXIT_FAILURE);
378}
379#endif
380
381UnitTestResult execute_guarded(UnitTest_function fun, long *duration_usec, long max_allowed_duration_ms, bool detect_environment_calls) {
382    if (GLOBAL.running_on_valgrind) max_allowed_duration_ms *= 4;
383    UnitTestResult result;
384
385    pid_t child_pid = fork();
386    if (child_pid) { // parent
387        try { result = execute_guarded_ClientCode(fun, duration_usec); }
388        catch (...) { result = TEST_THREW; }
389        if (kill(child_pid, SIGKILL) != 0) {
390            fprintf(stderr, "Failed to kill deadlock-guard (%s)\n", strerror(errno)); fflush(stderr);
391        }
392    }
393    else { // child
394#if (DEADLOCKGUARD == 1)
395        deadlockguard(max_allowed_duration_ms, detect_environment_calls);
396#else
397#warning DEADLOCKGUARD has been disabled (not default!)
398        detect_environment_calls = !!detect_environment_calls; // dont warn
399#endif
400        exit(EXIT_FAILURE);
401    }
402
403    return result;
404}
405
406// --------------------------------------------------------------------------------
407
408class SimpleTester {
409    const UnitTest_simple *tests;
410    const UnitTest_simple *postcond;
411    size_t                 count;
412    size_t                 postcount;
413    double                 duration_ms;
414
415    bool perform(size_t which);
416    UnitTestResult run_postcond(long *duration_usec, long max_allowed_duration_ms, bool print_errors);
417
418public:
419    SimpleTester(const UnitTest_simple *tests_, const UnitTest_simple *postcond_)
420        : tests(tests_),
421          postcond(postcond_),
422          duration_ms(0.0)
423    {
424        for (count = 0; tests[count].fun; ++count) {}
425        for (postcount = 0; postcond[postcount].fun; ++postcount) {}
426    }
427
428    size_t perform_all();
429    size_t get_test_count() const { return count; }
430
431    double overall_duration_ms() const { return duration_ms; }
432};
433
434
435size_t SimpleTester::perform_all() {
436    // returns number of passed tests
437
438    trace("performing %zu simple tests..", count);
439    size_t passed = 0;
440    for (size_t c = 0; c<count; ++c) {
441        GLOBAL.setup_test_precondition();
442        passed += perform(c);
443        GLOBAL.setup_test_postcondition();
444    }
445    return passed;
446}
447
448
449UnitTestResult SimpleTester::run_postcond(long *duration_usec_sum, long abort_after_ms, bool print_errors) {
450    UnitTestResult result = TEST_OK;
451    *duration_usec_sum    = 0;
452    for (size_t pc = 0; pc<postcount && result == TEST_OK; ++pc) {
453        long duration_usec;
454        result              = execute_guarded(postcond[pc].fun, &duration_usec, abort_after_ms, true); // <-- call postcond
455        *duration_usec_sum += duration_usec;
456
457        if (result != TEST_OK && print_errors) {
458            postcond[pc].print_error(stderr, result);
459        }
460    }
461    return result;
462}
463
464void UnitTest_simple::print_error(FILE *out, UnitTestResult result) const {
465    switch (result) {
466        case TEST_OK:
467            break;
468
469        case TEST_TRAPPED:
470            fprintf(out, "%s: Error: %s failed (details above)\n", location, name);
471            break;
472
473        case TEST_FAILED_POSTCONDITION:
474            fprintf(out, "%s: Error: %s succeeded, but violates general postconditions (see above)\n", location, name);
475            break;
476
477        case TEST_INTERRUPTED:
478            fprintf(out, "%s: Error: %s has been interrupted (details above)\n", location, name);
479            break;
480
481        case TEST_THREW:
482            fprintf(out, "%s: Error: %s has thrown an exception\n", location, name);
483            break;
484
485        case TEST_LACKS_LOCATION:
486            fprintf(out, "Error: %s lacks source location\n", name);
487            break;
488
489        case TEST_INVALID:
490            fprintf(out, "%s: Error: %s is invalid (see above)\n", location, name);
491            break;
492
493        case TEST_UNKNOWN_RESULT:
494            ut_assert(0);
495            break;
496    }
497}
498
499bool SimpleTester::perform(size_t which) {
500    ut_assert(which<count);
501
502    const UnitTest_simple& test = tests[which];
503    UnitTest_function      fun  = test.fun;
504
505    reset_test_local_flags();
506
507    bool       marked_as_slow = strlen(test.name) >= 10 && memcmp(test.name, "TEST_SLOW_", 10) == 0;
508    const long abort_after_ms = marked_as_slow ? MAX_EXEC_MS_SLOW : MAX_EXEC_MS_NORMAL;
509
510#if defined(EXPECT_VALID_TEST_LOCATION)
511    bool lacksLocation = !test.location;
512#else
513    bool lacksLocation = false; // in NDEBUG mode location is always missing (i.e. we dont expect to have one)
514#endif
515
516    UnitTestResult result = TEST_UNKNOWN_RESULT;
517    unsigned       tryMax = 1; // normally only try once; see ./README.txt@TEST_ALLOW_RETRY
518    for (unsigned tryCount = 1; tryCount<=tryMax && result != TEST_OK; ++tryCount) {
519        long duration_usec;
520        result                  = lacksLocation ? TEST_LACKS_LOCATION : execute_guarded(fun, &duration_usec, abort_after_ms, true); // <--- call unittest
521        double duration_ms_this = lacksLocation ? 0.0 : duration_usec/1000.0;
522
523        duration_ms += duration_ms_this;
524
525        long           duration_usec_post = 0;
526        UnitTestResult postcond_result    = TEST_UNKNOWN_RESULT;
527
528        if (result == TEST_OK) {
529            // if test is ok -> check postconditions
530            postcond_result = run_postcond(&duration_usec_post, MAX_EXEC_MS_NORMAL, true);
531            if (postcond_result != TEST_OK) {
532                result = TEST_FAILED_POSTCONDITION; // fail test, if any postcondition fails
533            }
534        }
535
536        trace("* %s = %s (%.1f ms)", test.name, get_readable_result(result), duration_ms_this);
537
538        if (result == TEST_OK) {
539            if (duration_ms_this >= WARN_SLOW_ABOVE_MS) {                    // long test duration
540                if (!marked_as_slow) {
541                    bool accept_slow = GLOBAL.running_on_valgrind || did_valgrinded_syscall();
542                    if (!accept_slow) {
543                        fprintf(stderr, "%s: Warning: Name of slow tests shall start with TEST_SLOW_ (it'll be run after other tests)\n",
544                                test.location);
545                    }
546                }
547            }
548        }
549
550        test.print_error(stderr, result);
551
552        if (result != TEST_OK) { // test did not succeed
553            if (tryCount == 1) { // 1st attempt failed
554                tryMax = arb_test::test_data().allowed_retries();
555                if (tryMax>1) {
556                    fprintf(stderr, "%s: Warning: test failed, but allows %u retries\n", test.location, tryMax-1);
557                }
558            }
559
560            if (result != TEST_FAILED_POSTCONDITION) { // postconditions not checked yet
561                // also check postconditions when test failed
562                // (because they are used to clean up side effects of failing tests)
563                SuppressOutput here;
564                postcond_result = run_postcond(&duration_usec_post, MAX_EXEC_MS_NORMAL, false); // but do not print anything
565            }
566        }
567
568        double duration_ms_postcond  = duration_usec_post/1000.0;
569        duration_ms                 += duration_ms_postcond;
570    }
571
572    return result == TEST_OK;
573}
574
575
576// --------------------------------------------------------------------------------
577
578static char text_buffer[100];
579
580inline const char *as_text(size_t z) { sprintf(text_buffer, "%zu", z); return text_buffer; }
581inline const char *as_text(double d) { sprintf(text_buffer, "%.1f", d); return text_buffer; }
582
583inline void appendValue(string& report, const char *tag, const char *value) { report = report+' '+tag+'='+value; }
584
585inline void appendValue(string& report, const char *tag, size_t value) { appendValue(report, tag, as_text(value)); }
586inline void appendValue(string& report, const char *tag, double value) { appendValue(report, tag, as_text(value)); }
587
588static const char *generateReport(const char *libname, size_t tests, size_t skipped, size_t passed, double duration_ms, size_t warnings) {
589    // generate a report consumed by reporter.pl@parse_log
590
591    static string report;
592    report.clear();
593
594    size_t tested = tests-skipped;
595    size_t failed = tested-passed;
596
597    appendValue(report, "target", libname);
598    appendValue(report, "time", duration_ms);
599    appendValue(report, "tests", tests);
600    if (skipped) appendValue(report, "skipped", skipped);
601    if (tests) {
602        if (!failed) appendValue(report, "passed", "ALL");
603        else         appendValue(report, "passed", passed);
604    }
605    if (failed) appendValue(report, "failed", failed);
606    if (warnings) appendValue(report, "warnings", warnings);
607
608    return report.c_str()+1; // skip leading space
609}
610
611const size_t Mb = 1024*1024;
612const size_t Gb = 1024*Mb;
613
614UnitTester::UnitTester(const char *libname, const UnitTest_simple *simple_tests, int warn_level, size_t skippedTests, const UnitTest_simple *postcond) {
615    // this is the "main()" of the unit test
616    // it is invoked from code generated by sym2testcode.pl@InvokeUnitTester
617
618#if !defined(LEAKS_SANITIZED) && !defined(UNDEF_SANITIZED)
619    // restrict memory available for test-code (does not work together with sanitizer)
620    ModRLimit restrict_virtual_memory(RLIMIT_AS, 1 * Gb);
621#endif
622
623    start_of_main();
624
625    TEST_EXPECT_ZERO_OR_SHOW_ERRNO(chdir("run"));
626    GLOBAL.runDir  = getcwd(NULp, ARB_PATH_MAX);
627    GLOBAL.libname = libname;
628
629    size_t tests  = 0;
630    size_t passed = 0;
631
632    {
633        arb_test::GlobalTestData& global = arb_test::test_data();
634
635        global.init(flag_callback);
636        global.show_warnings = (warn_level != 0);
637
638        double duration_ms = 0;
639        {
640            SimpleTester simple_tester(simple_tests, postcond);
641
642            tests = simple_tester.get_test_count();
643            if (tests) {
644                passed      = simple_tester.perform_all();
645                duration_ms = simple_tester.overall_duration_ms();
646            }
647        }
648
649        trace("%s", generateReport(libname,
650                                   tests+skippedTests, skippedTests, passed,
651                                   duration_ms, global.warnings));
652    }
653
654    arb_test::GlobalTestData::erase_instance();
655    exit(tests == passed ? EXIT_SUCCESS : EXIT_FAILURE);
656}
657
658
Note: See TracBrowser for help on using the repository browser.