# # # patch "tester-plaf.hh" # from [7492ac48c14abb8f61f57175fb31a78666bee01d] # to [b892b8cab5cd8d8571b5eea0282777883ea9a48c] # # patch "tester.cc" # from [9944326468bd2eb1ac21d19d103372d236f4dc1a] # to [13d974099651f132d26ffbf669bfbf9574875c01] # # patch "testlib.lua" # from [5807919b1b0111e8e2bacdc6589bb0d43eddae42] # to [8e6c3c361b1589b2c152eb0a7874f0271a6758e5] # # patch "unix/tester-plaf.cc" # from [033e1c858b94b338b8ed4f476855413379274bd9] # to [5cf32e316fdac4923c276ea3536ceec0100756a1] # # patch "win32/tester-plaf.cc" # from [4cae66ca767106b916ed327199590446f1cc0cc7] # to [b7a03cf159f5228fb467db08349691d57db6c310] # ============================================================ --- tester-plaf.hh 7492ac48c14abb8f61f57175fb31a78666bee01d +++ tester-plaf.hh b892b8cab5cd8d8571b5eea0282777883ea9a48c @@ -75,7 +75,8 @@ struct test_cleaner lua_State * st; int reporter_ref; test_cleaner(lua_State *st, int r) : st(st), reporter_ref(r) {} - bool operator()(test_to_run const & test, int status) const; + bool operator()(test_to_run const & test, int status, + int wall_seconds, int cpu_seconds) const; }; void run_tests_in_children(test_enumerator const & next_test, ============================================================ --- tester.cc 9944326468bd2eb1ac21d19d103372d236f4dc1a +++ tester.cc 13d974099651f132d26ffbf669bfbf9574875c01 @@ -648,7 +648,9 @@ bool test_cleaner::operator()(test_to_ru // Clean up after one child process. bool test_cleaner::operator()(test_to_run const & test, - int status) const + int status, + int wall_seconds, + int cpu_seconds) const { // call reporter(testno, testname, status) luaL_checkstack(st, 4, "preparing call to reporter"); @@ -657,7 +659,9 @@ bool test_cleaner::operator()(test_to_ru lua_pushinteger(st, test.number); lua_pushstring(st, test.name.c_str()); lua_pushinteger(st, status); - lua_call(st, 3, 1); + lua_pushinteger(st, wall_seconds); + lua_pushinteger(st, cpu_seconds); + lua_call(st, 5, 1); // return is a boolean. There is, for no apparent reason, no // luaL_checkboolean(). ============================================================ --- testlib.lua 5807919b1b0111e8e2bacdc6589bb0d43eddae42 +++ testlib.lua 8e6c3c361b1589b2c152eb0a7874f0271a6758e5 @@ -977,9 +977,9 @@ function run_tests(debugging, list_only, } -- callback closure passed to run_tests_in_children - local function report_one_test(tno, tname, status) + local function report_one_test(tno, tname, status, wall_seconds, cpu_seconds) local tdir = run_dir .. "/" .. tname - local test_header = string.format("%3d %-45s ", tno, tname) + local test_header = string.format("%3d %-45s", tno, tname) local what local can_delete -- the child should always exit successfully, just to avoid @@ -1029,7 +1029,19 @@ function run_tests(debugging, list_only, end counts.total = counts.total + 1 - P(string.format("%s%s\n", test_header, what)) + local format_seconds = function (seconds) + return string.format("%d:%02d", + seconds / 60, + seconds % 60) + end + local times = "" + if wall_seconds > -1 then + times = format_seconds(wall_seconds) + if cpu_seconds > -1 then + times = times . ", " . format_seconds(cpu_seconds) . " on CPU" + end + end + P(string.format("%s %s %s\n", test_header, what, times)) return (can_delete and not debugging) end ============================================================ --- unix/tester-plaf.cc 033e1c858b94b338b8ed4f476855413379274bd9 +++ unix/tester-plaf.cc 5cf32e316fdac4923c276ea3536ceec0100756a1 @@ -16,6 +16,7 @@ #include "tester-plaf.hh" #include +#include #include #include #include @@ -435,6 +436,59 @@ static void child(test_invoker const & i _exit(invoke(tname)); } +struct test_info +{ + test_to_run test; + time_t start_time; + + test_info(test_to_run t) : test(t), start_time(::time(0)) {} +}; +namespace { + typedef map child_map; + enum wait_type {WAIT_HANG, WAIT_NOHANG}; + + void wait_for_children(child_map & children, wait_type waitinfo, + test_cleaner const & cleanup, + std::string const & run_dir) + { + static int ticks_per_second = sysconf(_SC_CLK_TCK); + for (;;) + { + struct tms before, after; + int status; + // could use wait4(), but I don't think that's available everywhere + ::times(&before); + pid_t pid = waitpid(-1, &status, waitinfo == WAIT_NOHANG ? WNOHANG : 0); + ::times(&after); + if (pid == 0) + break; + if (pid == -1) + { + if (errno == ECHILD) + break; + if (errno == EINTR) + continue; + E(false, origin::system, + F("waitpid failed: %s") % os_strerror(errno)); + } + + map::iterator tfin = children.find(pid); + I(tfin != children.end()); + + int wall_seconds = ::time(0) - tfin->second.start_time; + intmax_t user_cpu_ticks = after.tms_cutime - before.tms_cutime; + intmax_t sys_cpu_ticks = after.tms_cstime - before.tms_cstime; + intmax_t cpu_ticks = user_cpu_ticks + sys_cpu_ticks; + int cpu_seconds = cpu_ticks / ticks_per_second; + + if (cleanup(tfin->second.test, status, wall_seconds, cpu_seconds)) + do_remove_recursive(run_dir + "/" + tfin->second.test.name); + children.erase(tfin); + release_token(); + } + } +} + void run_tests_in_children(test_enumerator const & next_test, test_invoker const & invoke, test_cleaner const & cleanup, @@ -445,7 +499,7 @@ void run_tests_in_children(test_enumerat { test_to_run t; string testdir; - map children; + child_map children; if (jobsvr_read_dup != -1) { @@ -468,29 +522,7 @@ void run_tests_in_children(test_enumerat if (jobsvr_read_dup == -1) jobsvr_read_dup = dup(jobsvr_read); - for (;;) - { - int status; - pid_t pid = waitpid(-1, &status, WNOHANG); - if (pid == 0) - break; - if (pid == -1) - { - if (errno == ECHILD) - break; - if (errno == EINTR) - continue; - E(false, origin::system, - F("waitpid failed: %s") % os_strerror(errno)); - } - - map::iterator tfin = children.find(pid); - I(tfin != children.end()); - if (cleanup(tfin->second, status)) - do_remove_recursive(run_dir + "/" + tfin->second.name); - children.erase(tfin); - release_token(); - } + wait_for_children(children, WAIT_NOHANG, cleanup, run_dir); } while (acquire_token()); @@ -506,7 +538,7 @@ void run_tests_in_children(test_enumerat } catch (...) { - cleanup(t, 121); + cleanup(t, 121, 0, 0); release_token(); continue; } @@ -519,7 +551,7 @@ void run_tests_in_children(test_enumerat child(invoke, testdir, t.name); else if (pid == -1) { - if (cleanup(t, 122)) + if (cleanup(t, 122, 0, 0)) do_remove_recursive(testdir); release_token(); } @@ -528,30 +560,8 @@ void run_tests_in_children(test_enumerat } // Now wait for any unfinished children. - for (;;) - { - int status; - pid_t pid = waitpid(-1, &status, 0); - if (pid == 0) - break; - if (pid == -1) - { - if (errno == ECHILD) - break; - if (errno == EINTR) - continue; - E(false, origin::system, - F("waitpid failed: %s") % os_strerror(errno)); - } + wait_for_children(children, WAIT_HANG, cleanup, run_dir); - map::iterator tfin = children.find(pid); - I(tfin != children.end()); - if (cleanup(tfin->second, status)) - do_remove_recursive(run_dir + "/" + tfin->second.name); - children.erase(tfin); - release_token(); - } - I(tokens_held == 0); I(children.size() == 0); if (jobsvr_read_dup != -1) ============================================================ --- win32/tester-plaf.cc 4cae66ca767106b916ed327199590446f1cc0cc7 +++ win32/tester-plaf.cc b7a03cf159f5228fb467db08349691d57db6c310 @@ -194,13 +194,14 @@ void run_tests_in_children(test_enumerat } catch (...) { - cleanup(t, 121); + cleanup(t, 121, 0, 0); continue; } change_current_working_dir(testdir); argv[4] = t.name.c_str(); pid_t child = process_spawn(argv); + DWORD start_millis = GetTickCount(); change_current_working_dir(run_dir); int status; @@ -209,7 +210,8 @@ void run_tests_in_children(test_enumerat else process_wait(child, &status); - if (cleanup(t, status)) + DWORD end_millis = GetTickCount(); + if (cleanup(t, status, (end_millis - start_millis) / 1000, -1)) do_remove_recursive(testdir); } }