From: Tom Lane <tgl@sss.pgh.pa.us>
To: pgsql-hackers@lists.postgresql.org
Subject: Reporting script runtimes in pg_regress
Date: Sat, 09 Feb 2019 22:50:18 -0500
Message-ID: <16646.1549770618@sss.pgh.pa.us> (raw)
I've wondered for some time whether we couldn't make a useful
reduction in the run time of the PG regression tests by looking
for scripts that run significantly longer than others in their
parallel groups, and making an effort to trim the runtimes of
those particular scripts.
The first step in that of course is to get some data, so attached
is a patch to pg_regress to cause it to print the runtime of each
script. This produces results like, say,
parallel group (17 tests): circle line timetz path lseg point macaddr macaddr8 time interval inet tstypes date box timestamp timestamptz polygon
point ... ok (35 ms)
lseg ... ok (31 ms)
line ... ok (23 ms)
box ... ok (135 ms)
path ... ok (24 ms)
polygon ... ok (1256 ms)
circle ... ok (20 ms)
date ... ok (69 ms)
time ... ok (40 ms)
timetz ... ok (22 ms)
timestamp ... ok (378 ms)
timestamptz ... ok (378 ms)
interval ... ok (50 ms)
inet ... ok (56 ms)
macaddr ... ok (33 ms)
macaddr8 ... ok (37 ms)
tstypes ... ok (62 ms)
or on a rather slower machine,
parallel group (8 tests): hash_part reloptions partition_info identity partition_join partition_aggregate partition_prune indexing
identity ... ok (3807 ms)
partition_join ... ok (10433 ms)
partition_prune ... ok (19370 ms)
reloptions ... ok (1166 ms)
hash_part ... ok (628 ms)
indexing ... ok (22070 ms)
partition_aggregate ... ok (12731 ms)
partition_info ... ok (1373 ms)
test event_trigger ... ok (1953 ms)
test fast_default ... ok (2689 ms)
test stats ... ok (1173 ms)
Does anyone else feel that this is interesting/useful data?
regards, tom lane
Attachments:print-test-script-runtimes-1.patch (text/x-diff, 4.3K) downloaddiff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.cindex 4b742a1..a4caa22 100644--- a/src/test/regress/pg_regress.c+++ b/src/test/regress/pg_regress.c@@ -36,6 +36,7 @@
#include "getopt_long.h"
#include "libpq/pqcomm.h" /* needed for UNIXSOCK_PATH() */
#include "pg_config_paths.h"
+#include "portability/instr_time.h"
/* for resultmap we need a list of pairs of strings */
typedef struct _resultmap
@@ -1473,14 +1474,15 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul
/*
* Wait for specified subprocesses to finish, and return their exit
- * statuses into statuses[]+ * statuses into statuses[] and stop times into stoptimes[]
*
* If names isn't NULL, print each subprocess's name as it finishes
*
* Note: it's OK to scribble on the pids array, but not on the names array
*/
static void
-wait_for_tests(PID_TYPE * pids, int *statuses, char **names, int num_tests)+wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes,+ char **names, int num_tests)
{
int tests_left;
int i;
@@ -1533,6 +1535,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, char **names, int num_tests)
#endif
pids[i] = INVALID_PID;
statuses[i] = (int) exit_status;
+ INSTR_TIME_SET_CURRENT(stoptimes[i]);
if (names)
status(" %s", names[i]);
tests_left--;
@@ -1582,6 +1585,8 @@ run_schedule(const char *schedule, test_function tfunc)
_stringlist *expectfiles[MAX_PARALLEL_TESTS];
_stringlist *tags[MAX_PARALLEL_TESTS];
PID_TYPE pids[MAX_PARALLEL_TESTS];
+ instr_time starttimes[MAX_PARALLEL_TESTS];+ instr_time stoptimes[MAX_PARALLEL_TESTS];
int statuses[MAX_PARALLEL_TESTS];
_stringlist *ignorelist = NULL;
char scbuf[1024];
@@ -1687,7 +1692,8 @@ run_schedule(const char *schedule, test_function tfunc)
{
status(_("test %-28s ... "), tests[0]);
pids[0] = (tfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]);
- wait_for_tests(pids, statuses, NULL, 1);+ INSTR_TIME_SET_CURRENT(starttimes[0]);+ wait_for_tests(pids, statuses, stoptimes, NULL, 1);
/* status line is finished below */
}
else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests)
@@ -1707,12 +1713,15 @@ run_schedule(const char *schedule, test_function tfunc)
if (i - oldest >= max_connections)
{
wait_for_tests(pids + oldest, statuses + oldest,
+ stoptimes + oldest,
tests + oldest, i - oldest);
oldest = i;
}
pids[i] = (tfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]);
+ INSTR_TIME_SET_CURRENT(starttimes[i]);
}
wait_for_tests(pids + oldest, statuses + oldest,
+ stoptimes + oldest,
tests + oldest, i - oldest);
status_end();
}
@@ -1722,8 +1731,9 @@ run_schedule(const char *schedule, test_function tfunc)
for (i = 0; i < num_tests; i++)
{
pids[i] = (tfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]);
+ INSTR_TIME_SET_CURRENT(starttimes[i]);
}
- wait_for_tests(pids, statuses, tests, num_tests);+ wait_for_tests(pids, statuses, stoptimes, tests, num_tests);
status_end();
}
@@ -1793,6 +1803,9 @@ run_schedule(const char *schedule, test_function tfunc)
if (statuses[i] != 0)
log_child_failure(statuses[i]);
+ INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]);+ status(_(" (%.0f ms)"), INSTR_TIME_GET_MILLISEC(stoptimes[i]));+
status_end();
}
@@ -1818,6 +1831,8 @@ static void
run_single_test(const char *test, test_function tfunc)
{
PID_TYPE pid;
+ instr_time starttime;+ instr_time stoptime;
int exit_status;
_stringlist *resultfiles = NULL;
_stringlist *expectfiles = NULL;
@@ -1829,7 +1844,8 @@ run_single_test(const char *test, test_function tfunc)
status(_("test %-28s ... "), test);
pid = (tfunc) (test, &resultfiles, &expectfiles, &tags);
- wait_for_tests(&pid, &exit_status, NULL, 1);+ INSTR_TIME_SET_CURRENT(starttime);+ wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1);
/*
* Advance over all three lists simultaneously.
@@ -1867,6 +1883,9 @@ run_single_test(const char *test, test_function tfunc)
if (exit_status != 0)
log_child_failure(exit_status);
+ INSTR_TIME_SUBTRACT(stoptime, starttime);+ status(_(" (%.0f ms)"), INSTR_TIME_GET_MILLISEC(stoptime));+
status_end();
}
=
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: tgl@sss.pgh.pa.us, pgsql-hackers@lists.postgresql.org
Subject: Re: Reporting script runtimes in pg_regress
In-Reply-To: <16646.1549770618@sss.pgh.pa.us>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox