public inbox for [email protected]help / color / mirror / Atom feed
[PATCH 1/1] Fix a corner-case in COPY FROM backslash processing. 14+ messages / 4 participants [nested] [flat]
* [PATCH 1/1] Fix a corner-case in COPY FROM backslash processing. @ 2021-02-03 12:00 Heikki Linnakangas <[email protected]> 0 siblings, 0 replies; 14+ messages in thread From: Heikki Linnakangas @ 2021-02-03 12:00 UTC (permalink / raw) If a multi-byte character is escaped with a backslash in TEXT mode input, we didn't always treat the escape correctly. If: - a multi-byte character is escaped with a backslash, and - the second byte of the character is 0x5C, i.e. the ASCII code of a backslash (\), and - the next character is a dot (.), then copyreadline we would incorrectly interpret the sequence as an end-of-copy marker (\.). this can only happen in encodings that can "embed" ascii characters as the second byte. one example of such sequence is '\x5ca45c2e666f6f' in Big5 encoding. If you put that in a file, and load it with COPY FROM, you'd incorrectly get an "end-of-copy marker corrupt" error. --- src/backend/commands/copyfromparse.c | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/src/backend/commands/copyfromparse.c b/src/backend/commands/copyfromparse.c index 798e18e013..c20ec482db 100644 --- a/src/backend/commands/copyfromparse.c +++ b/src/backend/commands/copyfromparse.c @@ -1084,7 +1084,7 @@ CopyReadLineText(CopyFromState cstate) break; } else if (!cstate->opts.csv_mode) - + { /* * If we are here, it means we found a backslash followed by * something other than a period. In non-CSV mode, anything @@ -1095,8 +1095,17 @@ CopyReadLineText(CopyFromState cstate) * backslashes are not special, so we want to process the * character after the backslash just like a normal character, * so we don't increment in those cases. + * + * In principle, we would need to use pg_encoding_mblen() to + * skip over the character in some encodings, like at the end + * of the loop. But if it's a multi-byte character, it cannot + * have any special meaning and skipping isn't necessary for + * correctness. We can fall through to process it normally + * instead. */ - raw_buf_ptr++; + if (!IS_HIGHBIT_SET(c2)) + raw_buf_ptr++; + } } /* -- 2.30.0 --------------97F3138F3612F1A4F9200D93-- ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-01-03 10:31 vignesh C <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: vignesh C @ 2023-01-03 10:31 UTC (permalink / raw) To: Daniel Gustafsson <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]>; Peter Eisentraut <[email protected]> On Tue, 29 Nov 2022 at 00:57, Daniel Gustafsson <[email protected]> wrote: > > > On 28 Nov 2022, at 20:02, Nikolay Shaplov <[email protected]> wrote: > > > From my reviewer's point of view patch is ready for commit. > > > > Thank you for your patience :-) > > Thanks for review. > > The attached tweaks a few comments and attempts to address the compiler warning > error in the CFBot CI. Not sure I entirely agree with the compiler there but > here is an attempt to work around it at least (by always copying the va_list > for the logfile). It also adds a missing va_end for the logfile va_list. > > I hope this is close to a final version of this patch (commitmessage needs a > bit of work though). > > > PS Should I change commitfest status? > > Sure, go ahead. > The patch does not apply on top of HEAD as in [1], please post a rebased patch: === Applying patches on top of PostgreSQL commit ID 92957ed98c5c565362ce665266132a7f08f6b0c0 === === applying patch ./v14-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch patching file meson.build Hunk #1 FAILED at 2968. 1 out of 1 hunk FAILED -- saving rejects to file meson.build.rej [1] - http://cfbot.cputube.org/patch_41_3837.log Regards, Vignesh ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-01-06 05:50 vignesh C <[email protected]> parent: vignesh C <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: vignesh C @ 2023-01-06 05:50 UTC (permalink / raw) To: Daniel Gustafsson <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]>; Peter Eisentraut <[email protected]> On Tue, 3 Jan 2023 at 16:01, vignesh C <[email protected]> wrote: > > On Tue, 29 Nov 2022 at 00:57, Daniel Gustafsson <[email protected]> wrote: > > > > > On 28 Nov 2022, at 20:02, Nikolay Shaplov <[email protected]> wrote: > > > > > From my reviewer's point of view patch is ready for commit. > > > > > > Thank you for your patience :-) > > > > Thanks for review. > > > > The attached tweaks a few comments and attempts to address the compiler warning > > error in the CFBot CI. Not sure I entirely agree with the compiler there but > > here is an attempt to work around it at least (by always copying the va_list > > for the logfile). It also adds a missing va_end for the logfile va_list. > > > > I hope this is close to a final version of this patch (commitmessage needs a > > bit of work though). > > > > > PS Should I change commitfest status? > > > > Sure, go ahead. > > > > The patch does not apply on top of HEAD as in [1], please post a rebased patch: > === Applying patches on top of PostgreSQL commit ID > 92957ed98c5c565362ce665266132a7f08f6b0c0 === > === applying patch > ./v14-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch > patching file meson.build > Hunk #1 FAILED at 2968. > 1 out of 1 hunk FAILED -- saving rejects to file meson.build.rej Attached a rebased patch on top of HEAD to try and see if we can close this patch in this commitfest. Regards, Vignesh Attachments: [text/x-patch] v15-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch (35.9K, ../../CALDaNm0WtGHpU5iZNfd8nDJ-avEw+btFNJvv7qVOPLy6BZG=dw@mail.gmail.com/2-v15-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch) download | inline diff: From 005bcf13037577a8682e3a6365b1b52bb2e48492 Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Fri, 6 Jan 2023 11:09:10 +0530 Subject: [PATCH v15] Change pg_regress output format to be TAP compliant This converts pg_regress output format to emit TAP complient output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Discussion: https://postgr.es/m/[email protected] --- meson.build | 1 + src/test/regress/pg_regress.c | 575 ++++++++++++++++++---------------- 2 files changed, 314 insertions(+), 262 deletions(-) diff --git a/meson.build b/meson.build index 45fb9dd616..7195937d17 100644 --- a/meson.build +++ b/meson.build @@ -3024,6 +3024,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 40e6c231a3..a05f423c75 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,26 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* For parallel tests, testnames are indented when printed for grouping */ +#define PARALLEL_INDENT 7 +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + DETAIL, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +123,7 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; static _resultmap *resultmap = NULL; @@ -116,12 +137,29 @@ static int fail_ignore_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel, bool ignore); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, bool ignore, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i\n", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NONE, "\n"); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -134,9 +172,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag(_("could not set core size: disallowed by hard limit\n")); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -202,53 +238,153 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel, bool ignore) { - va_list ap; + int testnumber; + int padding; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + testnumber = fail_count + fail_ignore_count + success_count; + padding = TESTNAME_WIDTH; - if (logfile) + /* + * Calculate the width for the testname field required to align runtimes + * vertically. + */ + if (parallel) + padding -= PARALLEL_INDENT; + + /* + * There is no NLS translation here as "(not) ok" and "SKIP" are protocol. + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are indented 8 + * spaces in case they run as part of a parallel group. The position for + * the runtime is offset based on that indentation. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms%s\n", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime, + /* Add an (igngored) comment on the SKIP line to clarify */ + (ignore ? " # SKIP (ignored)" : "")); +} + +static void +test_status_ok(const char *testname, double runtime, bool parallel) +{ + success_count++; + + test_status_print(true, testname, runtime, parallel, false); +} + +static void +test_status_failed(const char *testname, bool ignore, double runtime, bool parallel) +{ + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + if (ignore) { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); + fail_ignore_count++; + appendStringInfoString(failed_tests, " (ignored)"); } + else + fail_count++; + + test_status_print(false, testname, runtime, parallel, ignore); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); } -/* - * Done "doing something ..." - */ static void -status_end(void) +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) { - fprintf(stdout, "\n"); - fflush(stdout); + va_list argp_logfile; + FILE *fp; + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if (type == NOTE || type == DIAG || type == BAIL) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail Out!\n"); + if (logfile) + fprintf(logfile, "Bail Out!\n"); + } + + va_end(argp_logfile); + fflush(NULL); } /* @@ -272,9 +408,9 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d\n"), + r); } postmaster_running = false; @@ -332,9 +468,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail(_("could not create directory \"%s\": %s\n"), + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -456,9 +591,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail(_("could not open file \"%s\" for reading: %s\n"), + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -477,26 +611,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *expected++ = '\0'; @@ -742,13 +870,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note(_("(using postmaster on %s, port %s)\n"), pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note(_("(using postmaster on %s, default port)\n"), pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note(_("(using postmaster on Unix socket, port %s)\n"), pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note(_("(using postmaster on Unix socket, default port)\n")); } load_resultmap(); @@ -797,35 +925,27 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not open process token: error code %lu"), + GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not get token information buffer size: error code %lu"), + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not get token information: error code %lu\n"), + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not look up account SID: error code %lu\n"), + GetLastError()); } free(tokenuser); @@ -974,7 +1094,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1030,8 +1150,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail(_("command failed: %s\n"), buf->data); } /* Clean up */ @@ -1072,9 +1191,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail(_("could not fork: %s\n"), strerror(errno)); } if (pid == 0) { @@ -1089,9 +1206,10 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit(_("could not exec \"%s\": %s\n"), + shellprog, + strerror(errno)); } /* in parent */ return pid; @@ -1129,8 +1247,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag(_("could not open file \"%s\" for reading: %s\n"), + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1151,8 +1269,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag(_("could not open file \"%s\" for reading: %s\n"), + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1193,9 +1311,8 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail(_("could not create directory \"%s\": %s\n"), + dir, strerror(errno)); } } @@ -1245,8 +1362,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail(_("diff command failed with status %d: %s\n"), r, cmd); } #ifdef WIN32 @@ -1256,8 +1372,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail(_("diff command not found: %s\n"), cmd); } #endif @@ -1328,9 +1443,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail(_("Unable to check secondary comparison files: %s\n"), + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1445,9 +1559,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail(_("failed to wait for subprocesses: %s\n"), + strerror(errno)); } #else DWORD exit_status; @@ -1456,9 +1569,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail(_("failed to wait for subprocesses: error code %lu\n"), + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1477,7 +1589,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1496,21 +1608,21 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag(_("(test process exited with exit code %d)\n"), + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag(_("(test process was terminated by exception 0x%X)\n"), + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag(_("(test process was terminated by signal %d: %s)\n"), + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag(_("(test process exited with unrecognized status %d)\n"), + exitstatus); } /* @@ -1542,9 +1654,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail(_("could not open file \"%s\" for reading: %s\n"), + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1582,9 +1693,8 @@ run_schedule(const char *schedule, test_start_function startfunc, } else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail(_("syntax error in schedule file \"%s\" line %d: %s\n"), + schedule, line_num, scbuf); } num_tests = 0; @@ -1600,9 +1710,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail(_("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1624,14 +1733,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail(_("syntax error in schedule file \"%s\" line %d: %s\n"), + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1639,16 +1746,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail(_("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note(_("parallel group (%d tests, in groups of %d): "), + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1664,18 +1770,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note(_("parallel group (%d tests): "), num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1686,8 +1792,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1707,9 +1812,7 @@ run_schedule(const char *schedule, test_start_function startfunc, (*postfunc) (rl->str); newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) - { - printf("%s ", tl->str); - } + diag(_("tag: %s\n"), tl->str); differ |= newdiff; } @@ -1726,30 +1829,14 @@ run_schedule(const char *schedule, test_start_function startfunc, break; } } - if (ignore) - { - status(_("failed (ignored)")); - fail_ignore_count++; - } - else - { - status(_("FAILED")); - fail_count++; - } + + test_status_failed(tests[i], ignore, INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } else - { - status(_("ok ")); /* align with FAILED */ - success_count++; - } + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); if (statuses[i] != 0) log_child_failure(statuses[i]); - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1786,7 +1873,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1809,30 +1895,19 @@ run_single_test(const char *test, test_start_function startfunc, (*postfunc) (rl->str); newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) - { - printf("%s ", tl->str); - } + diag(_("tag: %s\n"), tl->str); differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (differ) - { - status(_("FAILED")); - fail_count++; - } + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime), false); else - { - status(_("ok ")); /* align with FAILED */ - success_count++; - } + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); if (exit_status != 0) log_child_failure(exit_status); - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1854,9 +1929,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail(_("%s: could not open file \"%s\" for writing: %s"), + progname, logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1865,9 +1939,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail(_("%s: could not open file \"%s\" for writing: %s"), + progname, difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1883,7 +1956,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1900,7 +1972,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1922,10 +1993,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1933,7 +2001,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1945,7 +2012,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2167,8 +2233,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2241,17 +2307,13 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail(_("%s: could not remove temp instance \"%s\""), + progname, temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2261,7 +2323,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2273,8 +2334,8 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail(_("%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s"), + progname, outputdir, buf); } /* @@ -2289,8 +2350,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail(_("%s: could not open \"%s\" for adding extra config: %s"), + progname, buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2309,8 +2370,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail(_("%s: could not open \"%s\" to read extra config: %s"), + progname, temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2349,14 +2410,14 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note(_("port %d apparently in use\n"), port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note(_("could not determine an available port\n")); + bail(_("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.")); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note(_("port %d apparently in use, trying %d\n"), + port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2368,7 +2429,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2380,11 +2440,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail(_("could not spawn postmaster: %s\n"), strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2419,16 +2475,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail(_("postmaster failed, examine %s/log/postmaster.log for the reason\n"), + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag(_("postmaster did not respond within %d seconds, examine %s/log/postmaster.log for the reason\n"), + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2437,17 +2493,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail(_("could not kill failed postmaster: %s"), strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail(_("could not kill failed postmaster: error code %lu"), + GetLastError()); #endif - - exit(2); + bail(_("postmaster failed")); } postmaster_running = true; @@ -2458,8 +2511,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note(_("running on port %d with PID %lu\n"), + port, ULONGPID(postmaster_pid)); } else { @@ -2490,8 +2543,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2507,7 +2558,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2518,62 +2568,63 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0 && fail_ignore_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"\n", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan((fail_count + fail_ignore_count + success_count)); /* * Emit nice-looking summary message */ if (fail_count == 0 && fail_ignore_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); - else if (fail_count == 0) /* fail_count=0, fail_ignore_count>0 */ - snprintf(buf, sizeof(buf), - _(" %d of %d tests passed, %d failed test(s) ignored. "), - success_count, - success_count + fail_ignore_count, - fail_ignore_count); - else if (fail_ignore_count == 0) /* fail_count>0 && fail_ignore_count=0 */ - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); + note(_("All %d tests passed.\n"), success_count); + /* fail_count=0, fail_ignore_count>0 */ + else if (fail_count == 0) + note(_("%d of %d tests passed, %d failed test(s) ignored.\n"), + success_count, + success_count + fail_ignore_count, + fail_ignore_count); + /* fail_count>0 && fail_ignore_count=0 */ + else if (fail_ignore_count == 0) + diag(_("%d of %d tests failed.\n"), + fail_count, + success_count + fail_count); + /* fail_count>0 && fail_ignore_count>0 */ else - /* fail_count>0 && fail_ignore_count>0 */ - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed, %d of these failures ignored. "), - fail_count + fail_ignore_count, - success_count + fail_count + fail_ignore_count, - fail_ignore_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag(_("%d of %d tests failed, %d of these failures ignored.\n"), + fail_count + fail_ignore_count, + success_count + fail_count + fail_ignore_count, + fail_ignore_count); + + if (fail_count > 0 || fail_ignore_count > 0) + diag(_("Failed and ignored tests:%s\n"), failed_tests->data); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag(_("The differences that caused some tests to fail can be viewed in the file \"%s\".\n"), + difffilename); + diag(_("A copy of the test summary that you see above is saved in the file \"%s\".\n"), + logfilename); } else { unlink(difffilename); unlink(logfilename); + + free(difffilename); + difffilename = NULL; + free(logfilename); + logfilename = NULL; } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.34.1 ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-01-19 11:14 vignesh C <[email protected]> parent: vignesh C <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: vignesh C @ 2023-01-19 11:14 UTC (permalink / raw) To: Daniel Gustafsson <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]>; Peter Eisentraut <[email protected]> On Fri, 6 Jan 2023 at 11:20, vignesh C <[email protected]> wrote: > > On Tue, 3 Jan 2023 at 16:01, vignesh C <[email protected]> wrote: > > > > On Tue, 29 Nov 2022 at 00:57, Daniel Gustafsson <[email protected]> wrote: > > > > > > > On 28 Nov 2022, at 20:02, Nikolay Shaplov <[email protected]> wrote: > > > > > > > From my reviewer's point of view patch is ready for commit. > > > > > > > > Thank you for your patience :-) > > > > > > Thanks for review. > > > > > > The attached tweaks a few comments and attempts to address the compiler warning > > > error in the CFBot CI. Not sure I entirely agree with the compiler there but > > > here is an attempt to work around it at least (by always copying the va_list > > > for the logfile). It also adds a missing va_end for the logfile va_list. > > > > > > I hope this is close to a final version of this patch (commitmessage needs a > > > bit of work though). > > > > > > > PS Should I change commitfest status? > > > > > > Sure, go ahead. > > > > > > > The patch does not apply on top of HEAD as in [1], please post a rebased patch: > > === Applying patches on top of PostgreSQL commit ID > > 92957ed98c5c565362ce665266132a7f08f6b0c0 === > > === applying patch > > ./v14-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch > > patching file meson.build > > Hunk #1 FAILED at 2968. > > 1 out of 1 hunk FAILED -- saving rejects to file meson.build.rej > > Attached a rebased patch on top of HEAD to try and see if we can close > this patch in this commitfest. The patch does not apply on top of HEAD as in [1], please post a rebased patch: === applying patch ./v15-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch patching file meson.build patching file src/test/regress/pg_regress.c ... Hunk #58 FAILED at 2584. 2 out of 58 hunks FAILED -- saving rejects to file src/test/regress/pg_regress.c.rej [1] - http://cfbot.cputube.org/patch_41_3837.log Regards, Vignesh ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-01-23 11:42 Daniel Gustafsson <[email protected]> parent: vignesh C <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-01-23 11:42 UTC (permalink / raw) To: vignesh C <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]>; Peter Eisentraut <[email protected]> > On 19 Jan 2023, at 12:14, vignesh C <[email protected]> wrote: > The patch does not apply on top of HEAD as in [1], please post a rebased patch: The attached v16 is a rebase on top of current master which resolves the conflict which came from the recent commit removing the "ignore" functionality. It also fixes a few small things pointed out off-list. -- Daniel Gustafsson ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-01-23 11:43 Daniel Gustafsson <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-01-23 11:43 UTC (permalink / raw) To: vignesh C <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]>; Peter Eisentraut <[email protected]> > On 23 Jan 2023, at 12:42, Daniel Gustafsson <[email protected]> wrote: > >> On 19 Jan 2023, at 12:14, vignesh C <[email protected]> wrote: > >> The patch does not apply on top of HEAD as in [1], please post a rebased patch: > > The attached v16 is a rebase on top of current master which resolves the > conflict which came from the recent commit removing the "ignore" functionality. > It also fixes a few small things pointed out off-list. And now with the missing attachment.. -- Daniel Gustafsson Attachments: [application/octet-stream] v16-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch (34.1K, ../../[email protected]/2-v16-0001-Change-pg_regress-output-format-to-be-TAP-compli.patch) download | inline diff: From b3adf7d1c1beb6e910f774989bda0947d30806d4 Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Mon, 23 Jan 2023 12:21:16 +0100 Subject: [PATCH v16] Change pg_regress output format to be TAP compliant This converts pg_regress output format to emit TAP complient output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Discussion: https://postgr.es/m/[email protected] --- meson.build | 1 + src/test/regress/pg_regress.c | 535 ++++++++++++++++++---------------- 2 files changed, 291 insertions(+), 245 deletions(-) diff --git a/meson.build b/meson.build index 45fb9dd616..7195937d17 100644 --- a/meson.build +++ b/meson.build @@ -3024,6 +3024,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 6cd5998b9d..83fbee89bd 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,26 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* For parallel tests, testnames are indented when printed for grouping */ +#define PARALLEL_INDENT 7 +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + DETAIL, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +123,7 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; static _resultmap *resultmap = NULL; @@ -115,12 +136,29 @@ static int fail_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i\n", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NONE, "\n"); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -133,9 +171,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag(_("could not set core size: disallowed by hard limit\n")); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -201,53 +237,145 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel) { - va_list ap; + int testnumber; + int padding; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + testnumber = fail_count + success_count; + padding = TESTNAME_WIDTH; - if (logfile) - { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); - } + /* + * Calculate the width for the testname field required to align runtimes + * vertically. + */ + if (parallel) + padding -= PARALLEL_INDENT; + + /* + * There is no NLS translation here as "not ok" and "ok" are protocol. + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are indented 8 + * spaces in case they run as part of a parallel group. The position for + * the runtime is offset based on that indentation. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms\n", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime); } -/* - * Done "doing something ..." - */ static void -status_end(void) +test_status_ok(const char *testname, double runtime, bool parallel) { - fprintf(stdout, "\n"); - fflush(stdout); + success_count++; + + test_status_print(true, testname, runtime, parallel); +} + +static void +test_status_failed(const char *testname, double runtime, bool parallel) +{ + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + fail_count++; + + test_status_print(false, testname, runtime, parallel); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); +} + +static void +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) +{ + va_list argp_logfile; + FILE *fp; + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if (type == NOTE || type == DIAG || type == BAIL) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail Out!\n"); + if (logfile) + fprintf(logfile, "Bail Out!\n"); + } + + va_end(argp_logfile); + fflush(NULL); } /* @@ -271,9 +399,9 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d\n"), + r); } postmaster_running = false; @@ -331,9 +459,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail(_("could not create directory \"%s\": %s\n"), + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -455,9 +582,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail(_("could not open file \"%s\" for reading: %s\n"), + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -476,26 +602,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *expected++ = '\0'; @@ -741,13 +861,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note(_("(using postmaster on %s, port %s)\n"), pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note(_("(using postmaster on %s, default port)\n"), pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note(_("(using postmaster on Unix socket, port %s)\n"), pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note(_("(using postmaster on Unix socket, default port)\n")); } load_resultmap(); @@ -796,35 +916,27 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not open process token: error code %lu"), + GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not get token information buffer size: error code %lu"), + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not get token information: error code %lu\n"), + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not look up account SID: error code %lu\n"), + GetLastError()); } free(tokenuser); @@ -973,7 +1085,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1029,8 +1141,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail(_("command failed: %s\n"), buf->data); } /* Clean up */ @@ -1071,9 +1182,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail(_("could not fork: %s\n"), strerror(errno)); } if (pid == 0) { @@ -1088,9 +1197,10 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit(_("could not exec \"%s\": %s\n"), + shellprog, + strerror(errno)); } /* in parent */ return pid; @@ -1128,8 +1238,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag(_("could not open file \"%s\" for reading: %s\n"), + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1150,8 +1260,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag(_("could not open file \"%s\" for reading: %s\n"), + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1192,9 +1302,8 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail(_("could not create directory \"%s\": %s\n"), + dir, strerror(errno)); } } @@ -1244,8 +1353,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail(_("diff command failed with status %d: %s\n"), r, cmd); } #ifdef WIN32 @@ -1255,8 +1363,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail(_("diff command not found: %s\n"), cmd); } #endif @@ -1327,9 +1434,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail(_("Unable to check secondary comparison files: %s\n"), + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1444,9 +1550,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail(_("failed to wait for subprocesses: %s\n"), + strerror(errno)); } #else DWORD exit_status; @@ -1455,9 +1560,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail(_("failed to wait for subprocesses: error code %lu\n"), + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1476,7 +1580,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1495,21 +1599,21 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag(_("(test process exited with exit code %d)\n"), + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag(_("(test process was terminated by exception 0x%X)\n"), + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag(_("(test process was terminated by signal %d: %s)\n"), + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag(_("(test process exited with unrecognized status %d)\n"), + exitstatus); } /* @@ -1540,9 +1644,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail(_("could not open file \"%s\" for reading: %s\n"), + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1566,9 +1669,8 @@ run_schedule(const char *schedule, test_start_function startfunc, test = scbuf + 6; else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail(_("syntax error in schedule file \"%s\" line %d: %s\n"), + schedule, line_num, scbuf); } num_tests = 0; @@ -1584,9 +1686,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail(_("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1608,14 +1709,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail(_("syntax error in schedule file \"%s\" line %d: %s\n"), + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1623,16 +1722,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail(_("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note(_("parallel group (%d tests, in groups of %d): "), + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1648,18 +1746,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note(_("parallel group (%d tests): "), num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1670,8 +1768,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1691,30 +1788,17 @@ run_schedule(const char *schedule, test_start_function startfunc, (*postfunc) (rl->str); newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) - { - printf("%s ", tl->str); - } + diag(_("tag: %s\n"), tl->str); differ |= newdiff; } if (differ) - { - status(_("FAILED")); - fail_count++; - } + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); else - { - status(_("ok ")); /* align with FAILED */ - success_count++; - } + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); if (statuses[i] != 0) log_child_failure(statuses[i]); - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1749,7 +1833,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1772,30 +1855,19 @@ run_single_test(const char *test, test_start_function startfunc, (*postfunc) (rl->str); newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) - { - printf("%s ", tl->str); - } + diag(_("tag: %s\n"), tl->str); differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (differ) - { - status(_("FAILED")); - fail_count++; - } + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); else - { - status(_("ok ")); /* align with FAILED */ - success_count++; - } + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); if (exit_status != 0) log_child_failure(exit_status); - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1817,9 +1889,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail(_("%s: could not open file \"%s\" for writing: %s"), + progname, logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1828,9 +1899,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail(_("%s: could not open file \"%s\" for writing: %s"), + progname, difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1846,7 +1916,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1863,7 +1932,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1885,10 +1953,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1896,7 +1961,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1908,7 +1972,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2130,8 +2193,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2204,17 +2267,13 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail(_("%s: could not remove temp instance \"%s\""), + progname, temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2224,7 +2283,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2236,8 +2294,8 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail(_("%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s"), + progname, outputdir, buf); } /* @@ -2252,8 +2310,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail(_("%s: could not open \"%s\" for adding extra config: %s"), + progname, buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2272,8 +2330,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail(_("%s: could not open \"%s\" to read extra config: %s"), + progname, temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2312,14 +2370,14 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note(_("port %d apparently in use\n"), port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note(_("could not determine an available port\n")); + bail(_("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.")); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note(_("port %d apparently in use, trying %d\n"), + port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2331,7 +2389,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2343,11 +2400,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail(_("could not spawn postmaster: %s\n"), strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2382,16 +2435,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail(_("postmaster failed, examine %s/log/postmaster.log for the reason\n"), + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag(_("postmaster did not respond within %d seconds, examine %s/log/postmaster.log for the reason\n"), + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2400,17 +2453,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail(_("could not kill failed postmaster: %s"), strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail(_("could not kill failed postmaster: error code %lu"), + GetLastError()); #endif - - exit(2); + bail(_("postmaster failed")); } postmaster_running = true; @@ -2421,8 +2471,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note(_("running on port %d with PID %lu\n"), + port, ULONGPID(postmaster_pid)); } else { @@ -2453,8 +2503,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2470,7 +2518,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2481,49 +2528,47 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"\n", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan(fail_count + success_count); /* * Emit nice-looking summary message */ if (fail_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); + note(_("All %d tests passed.\n"), success_count); else - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag(_("%d of %d tests failed.\n"), + fail_count, + success_count + fail_count); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag(_("The differences that caused some tests to fail can be viewed in the file \"%s\".\n"), + difffilename); + diag(_("A copy of the test summary that you see above is saved in the file \"%s\".\n"), + logfilename); } else { unlink(difffilename); unlink(logfilename); + + free(difffilename); + difffilename = NULL; + free(logfilename); + logfilename = NULL; } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.32.1 (Apple Git-133) ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-02-24 09:49 Daniel Gustafsson <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-02-24 09:49 UTC (permalink / raw) To: vignesh C <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]>; Peter Eisentraut <[email protected]> Another rebase on top of 337903a16f. Unless there are conflicting reviews, I consider this patch to be done and ready for going in during the next CF. -- Daniel Gustafsson Attachments: [application/octet-stream] v17-0001-Emit-TAP-compliant-output-from-pg_regress.patch (34.4K, ../../[email protected]/2-v17-0001-Emit-TAP-compliant-output-from-pg_regress.patch) download | inline diff: From 2da871c30ae3af33a5e0cfb329fe8106b093fa16 Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Fri, 24 Feb 2023 10:44:25 +0100 Subject: [PATCH v17] Emit TAP compliant output from pg_regress This converts pg_regress output format to emit TAP compliant output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Discussion: https://postgr.es/m/[email protected] --- meson.build | 1 + src/test/regress/pg_regress.c | 530 +++++++++++++++++++--------------- 2 files changed, 293 insertions(+), 238 deletions(-) diff --git a/meson.build b/meson.build index 656777820c..fba042bd36 100644 --- a/meson.build +++ b/meson.build @@ -3012,6 +3012,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 7b23cc80dc..47ae6de249 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,26 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* For parallel tests, testnames are indented when printed for grouping */ +#define PARALLEL_INDENT 7 +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + DETAIL, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +123,7 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; static _resultmap *resultmap = NULL; @@ -115,12 +136,29 @@ static int fail_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i\n", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NONE, "\n"); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -133,9 +171,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag(_("could not set core size: disallowed by hard limit\n")); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -201,53 +237,145 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel) { - va_list ap; + int testnumber; + int padding; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + testnumber = fail_count + success_count; + padding = TESTNAME_WIDTH; - if (logfile) - { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); - } + /* + * Calculate the width for the testname field required to align runtimes + * vertically. + */ + if (parallel) + padding -= PARALLEL_INDENT; + + /* + * There is no NLS translation here as "not ok" and "ok" are protocol. + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are indented 8 + * spaces in case they run as part of a parallel group. The position for + * the runtime is offset based on that indentation. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms\n", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime); +} + +static void +test_status_ok(const char *testname, double runtime, bool parallel) +{ + success_count++; + + test_status_print(true, testname, runtime, parallel); } -/* - * Done "doing something ..." - */ static void -status_end(void) +test_status_failed(const char *testname, double runtime, bool parallel) { - fprintf(stdout, "\n"); - fflush(stdout); + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + fail_count++; + + test_status_print(false, testname, runtime, parallel); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); +} + +static void +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) +{ + va_list argp_logfile; + FILE *fp; + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if (type == NOTE || type == DIAG || type == BAIL) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail Out!\n"); + if (logfile) + fprintf(logfile, "Bail Out!\n"); + } + + va_end(argp_logfile); + fflush(NULL); } /* @@ -271,9 +399,9 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d\n"), + r); } postmaster_running = false; @@ -331,9 +459,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail(_("could not create directory \"%s\": %s\n"), + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -455,9 +582,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail(_("could not open file \"%s\" for reading: %s\n"), + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -476,26 +602,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail(_("incorrectly formatted resultmap entry: %s\n"), buf); } *expected++ = '\0'; @@ -741,13 +861,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note(_("(using postmaster on %s, port %s)\n"), pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note(_("(using postmaster on %s, default port)\n"), pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note(_("(using postmaster on Unix socket, port %s)\n"), pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note(_("(using postmaster on Unix socket, default port)\n")); } load_resultmap(); @@ -796,35 +916,27 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not open process token: error code %lu"), + GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not get token information buffer size: error code %lu"), + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not get token information: error code %lu\n"), + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail(_("could not look up account SID: error code %lu\n"), + GetLastError()); } free(tokenuser); @@ -973,7 +1085,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1029,8 +1141,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail(_("command failed: %s\n"), buf->data); } /* Clean up */ @@ -1071,9 +1182,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail(_("could not fork: %s\n"), strerror(errno)); } if (pid == 0) { @@ -1088,9 +1197,10 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit(_("could not exec \"%s\": %s\n"), + shellprog, + strerror(errno)); } /* in parent */ return pid; @@ -1128,8 +1238,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag(_("could not open file \"%s\" for reading: %s\n"), + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1150,8 +1260,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag(_("could not open file \"%s\" for reading: %s\n"), + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1192,9 +1302,8 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail(_("could not create directory \"%s\": %s\n"), + dir, strerror(errno)); } } @@ -1244,8 +1353,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail(_("diff command failed with status %d: %s\n"), r, cmd); } #ifdef WIN32 @@ -1255,8 +1363,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail(_("diff command not found: %s\n"), cmd); } #endif @@ -1327,9 +1434,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail(_("Unable to check secondary comparison files: %s\n"), + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1444,9 +1550,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail(_("failed to wait for subprocesses: %s\n"), + strerror(errno)); } #else DWORD exit_status; @@ -1455,9 +1560,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail(_("failed to wait for subprocesses: error code %lu\n"), + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1476,7 +1580,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1495,21 +1599,21 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag(_("(test process exited with exit code %d)\n"), + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag(_("(test process was terminated by exception 0x%X)\n"), + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag(_("(test process was terminated by signal %d: %s)\n"), + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag(_("(test process exited with unrecognized status %d)\n"), + exitstatus); } /* @@ -1540,9 +1644,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail(_("could not open file \"%s\" for reading: %s\n"), + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1566,9 +1669,8 @@ run_schedule(const char *schedule, test_start_function startfunc, test = scbuf + 6; else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail(_("syntax error in schedule file \"%s\" line %d: %s\n"), + schedule, line_num, scbuf); } num_tests = 0; @@ -1584,9 +1686,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail(_("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1608,14 +1709,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail(_("syntax error in schedule file \"%s\" line %d: %s\n"), + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1623,16 +1722,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail(_("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note(_("parallel group (%d tests, in groups of %d): "), + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1648,18 +1746,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note(_("parallel group (%d tests): "), num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1670,8 +1768,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1692,36 +1789,27 @@ run_schedule(const char *schedule, test_start_function startfunc, newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag(_("tag: %s\n"), tl->str); } differ |= newdiff; } if (statuses[i] != 0) { - status(_("FAILED")); + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); log_child_failure(statuses[i]); - fail_count++; } else { - if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } } - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1756,7 +1844,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1780,35 +1867,29 @@ run_single_test(const char *test, test_start_function startfunc, newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag(_("tag: %s\n"), tl->str); } differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (exit_status != 0) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); log_child_failure(exit_status); } else { if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); } } - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1830,9 +1911,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail(_("%s: could not open file \"%s\" for writing: %s"), + progname, logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1841,9 +1921,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail(_("%s: could not open file \"%s\" for writing: %s"), + progname, difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1859,7 +1938,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1876,7 +1954,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1898,10 +1975,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1909,7 +1983,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1921,7 +1994,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2143,8 +2215,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2217,17 +2289,13 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail(_("%s: could not remove temp instance \"%s\""), + progname, temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2237,7 +2305,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2249,8 +2316,8 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail(_("%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s"), + progname, outputdir, buf); } /* @@ -2265,8 +2332,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail(_("%s: could not open \"%s\" for adding extra config: %s"), + progname, buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2285,8 +2352,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail(_("%s: could not open \"%s\" to read extra config: %s"), + progname, temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2325,14 +2392,14 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note(_("port %d apparently in use\n"), port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note(_("could not determine an available port\n")); + bail(_("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.")); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note(_("port %d apparently in use, trying %d\n"), + port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2344,7 +2411,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2356,11 +2422,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail(_("could not spawn postmaster: %s\n"), strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2395,16 +2457,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail(_("postmaster failed, examine %s/log/postmaster.log for the reason\n"), + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag(_("postmaster did not respond within %d seconds, examine %s/log/postmaster.log for the reason\n"), + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2413,17 +2475,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail(_("could not kill failed postmaster: %s"), strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail(_("could not kill failed postmaster: error code %lu"), + GetLastError()); #endif - - exit(2); + bail(_("postmaster failed")); } postmaster_running = true; @@ -2434,8 +2493,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note(_("running on port %d with PID %lu\n"), + port, ULONGPID(postmaster_pid)); } else { @@ -2466,8 +2525,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2483,7 +2540,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2494,49 +2550,47 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"\n", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan(fail_count + success_count); /* * Emit nice-looking summary message */ if (fail_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); + note(_("All %d tests passed.\n"), success_count); else - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag(_("%d of %d tests failed.\n"), + fail_count, + success_count + fail_count); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag(_("The differences that caused some tests to fail can be viewed in the file \"%s\".\n"), + difffilename); + diag(_("A copy of the test summary that you see above is saved in the file \"%s\".\n"), + logfilename); } else { unlink(difffilename); unlink(logfilename); + + free(difffilename); + difffilename = NULL; + free(logfilename); + logfilename = NULL; } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.32.1 (Apple Git-133) ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-15 10:36 Peter Eisentraut <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Peter Eisentraut @ 2023-03-15 10:36 UTC (permalink / raw) To: Daniel Gustafsson <[email protected]>; vignesh C <[email protected]>; +Cc: Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> On 24.02.23 10:49, Daniel Gustafsson wrote: > Another rebase on top of 337903a16f. Unless there are conflicting reviews, I > consider this patch to be done and ready for going in during the next CF. I think this is just about as good as it's going to get, so I think we can consider committing this soon. A few comments along the way: 1) We can remove the gettext markers _() inside calls like note(), bail(), etc. If we really wanted to do translation, we would do that inside those functions (similar to errmsg() etc.). 2) There are a few fprintf(stderr, ...) calls left. Should those be changed to something TAP-enabled? 3) Maybe these lines +++ isolation check in src/test/isolation +++ should be changed to TAP format? Arguably, if I run "make -s check", then everything printed should be valid TAP, right? 4) From the introduction lines ============== creating temporary instance ============== ============== initializing database system ============== ============== starting postmaster ============== running on port 61696 with PID 85346 ============== creating database "regression" ============== ============== running regression test queries ============== you have kept # running on port 61696 with PID 85346 which, well, is that the most interesting of those? The first three lines (creating, initializing, starting) take some noticeable amount of time, so they could be kept as a progress indicator. Or just delete all of them? I suppose some explicit indication about temp-instance versus existing instance would be useful. 5) About the output format. Obviously, this will require some retraining of the eye. But my first impression is that there is a lot of whitespace without any guiding lines, so to speak, horizontally or vertically. It makes me a bit dizzy. ;-) I think instead # parallel group (2 tests): event_trigger oidjoins ok 210 event_trigger 131 ms ok 211 oidjoins 190 ms ok 212 fast_default 158 ms ok 213 tablespace 319 ms Something like this would be less dizzy-making: # parallel group (2 tests): event_trigger oidjoins ok 210 - + event_trigger 131 ms ok 211 - + oidjoins 190 ms ok 212 - fast_default 158 ms ok 213 - tablespace 319 ms Just an idea, we don't have to get this exactly perfect right now, but it's something to think about. I think if 1-4 are addressed, this can be committed. ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-28 13:26 Daniel Gustafsson <[email protected]> parent: Peter Eisentraut <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-03-28 13:26 UTC (permalink / raw) To: Peter Eisentraut <[email protected]>; +Cc: vignesh C <[email protected]>; Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> > On 15 Mar 2023, at 11:36, Peter Eisentraut <[email protected]> wrote: > > On 24.02.23 10:49, Daniel Gustafsson wrote: >> Another rebase on top of 337903a16f. Unless there are conflicting reviews, I >> consider this patch to be done and ready for going in during the next CF. > > I think this is just about as good as it's going to get, so I think we can consider committing this soon. > > A few comments along the way: > > 1) We can remove the gettext markers _() inside calls like note(), bail(), etc. If we really wanted to do translation, we would do that inside those functions (similar to errmsg() etc.). Fixed. The attached also removes all explicit \n from output and leaves the decision on when to add a linebreak to the TAP emitting function. I think this better match how we typically handle printing of output like this. It also ensures that all bail messages follow the same syntax. > 2) There are a few fprintf(stderr, ...) calls left. Should those be changed to something TAP-enabled? Initially the patch kept errors happening before testing started a non-TAP output, there were leftovers which are now converted. > 3) Maybe these lines > > +++ isolation check in src/test/isolation +++ > > should be changed to TAP format? Arguably, if I run "make -s check", then everything printed should be valid TAP, right? Fixed. > 4) From the introduction lines > > ============== creating temporary instance ============== > ============== initializing database system ============== > ============== starting postmaster ============== > running on port 61696 with PID 85346 > ============== creating database "regression" ============== > ============== running regression test queries ============== > > you have kept > > # running on port 61696 with PID 85346 > > which, well, is that the most interesting of those? > > The first three lines (creating, initializing, starting) take some noticeable amount of time, so they could be kept as a progress indicator. Or just delete all of them? I suppose some explicit indication about temp-instance versus existing instance would be useful. This was discussed in [email protected] which concluded that this was about the only thing of interest, and even at that it was more of a maybe than a definite yes. As this patch stands, it prints the above for a temp install and the host/port for an existing install, but I don't have ny problems removing that as well. > 5) About the output format. Obviously, this will require some retraining of the eye. But my first impression is that there is a lot of whitespace without any guiding lines, so to speak, horizontally or vertically. It makes me a bit dizzy. ;-) > > I think instead > > # parallel group (2 tests): event_trigger oidjoins > ok 210 event_trigger 131 ms > ok 211 oidjoins 190 ms > ok 212 fast_default 158 ms > ok 213 tablespace 319 ms > > Something like this would be less dizzy-making: > > # parallel group (2 tests): event_trigger oidjoins > ok 210 - + event_trigger 131 ms > ok 211 - + oidjoins 190 ms > ok 212 - fast_default 158 ms > ok 213 - tablespace 319 ms The current format is chosen to be close to the old format, while also adding sufficient padding that it won't yield ragged columns. The wide padding is needed to cope with long names in the isolation and ecgp test suites and not so much regress suite. In the attached I've dialled back the padding a little bit to make it a bit more compact, but I doubt it's enough. > Just an idea, we don't have to get this exactly perfect right now, but it's something to think about. I'm quite convinced that this will be revisited once this lands and is in front of developers. I think the attached is a good candidate for going in, but I would like to see it for another spin in the CF bot first. -- Daniel Gustafsson Attachments: [application/octet-stream] v18-0001-pg_regress-Emit-TAP-compliant-output.patch (40.0K, ../../[email protected]/2-v18-0001-pg_regress-Emit-TAP-compliant-output.patch) download | inline diff: From 38d47544bf3dfc63daf15849b93704e0fb8b95b5 Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Tue, 28 Mar 2023 15:20:19 +0200 Subject: [PATCH v18] pg_regress: Emit TAP compliant output MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This converts pg_regress output format to emit TAP compliant output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Reviewed-by: Andres Freund <[email protected]> Reviewed-by: Tom Lane <[email protected]> Reviewed-by: Nikolay Shaplov <[email protected]> Reviewed-by: Dagfinn Ilmari Mannsåker <[email protected]> Reviewed-by: Peter Eisentraut <[email protected]> Discussion: https://postgr.es/m/[email protected] Discussion: https://postgr.es/m/[email protected] --- meson.build | 1 + src/Makefile.global.in | 14 +- src/test/regress/pg_regress.c | 587 +++++++++++++++++++--------------- 3 files changed, 341 insertions(+), 261 deletions(-) diff --git a/meson.build b/meson.build index 61e94be864..dd23acee54 100644 --- a/meson.build +++ b/meson.build @@ -3118,6 +3118,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/Makefile.global.in b/src/Makefile.global.in index fb3e197fc0..9a7d41b727 100644 --- a/src/Makefile.global.in +++ b/src/Makefile.global.in @@ -444,7 +444,7 @@ ifeq ($(enable_tap_tests),yes) ifndef PGXS define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "\# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -457,7 +457,7 @@ cd $(srcdir) && \ endef else # PGXS case define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "\# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -471,7 +471,7 @@ endef endif # PGXS define prove_check -echo "+++ tap check in $(subdir) +++" && \ +echo "\# +++ tap check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -665,7 +665,7 @@ pg_regress_locale_flags = $(if $(ENCODING),--encoding=$(ENCODING)) $(NOLOCALE) pg_regress_clean_files = results/ regression.diffs regression.out tmp_check/ tmp_check_iso/ log/ output_iso/ pg_regress_check = \ - echo "+++ regress check in $(subdir) +++" && \ + echo "\# +++ regress check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/regress/pg_regress \ --temp-instance=./tmp_check \ @@ -674,14 +674,14 @@ pg_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_regress_installcheck = \ - echo "+++ regress install-check in $(subdir) +++" && \ + echo "\# +++ regress install-check in $(subdir) +++" && \ $(top_builddir)/src/test/regress/pg_regress \ --inputdir=$(srcdir) \ --bindir='$(bindir)' \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_check = \ - echo "+++ isolation check in $(subdir) +++" && \ + echo "\# +++ isolation check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --temp-instance=./tmp_check_iso \ @@ -690,7 +690,7 @@ pg_isolation_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_installcheck = \ - echo "+++ isolation install-check in $(subdir) +++" && \ + echo "\# +++ isolation install-check in $(subdir) +++" && \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --inputdir=$(srcdir) --outputdir=output_iso \ --bindir='$(bindir)' \ diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 7b23cc80dc..867f72ecdb 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,27 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* For parallel tests, testnames are indented when printed for grouping */ +#define PARALLEL_INDENT 3 +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + NOTE_DETAIL, + NOTE_END, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +124,8 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; +static bool in_note = false; static _resultmap *resultmap = NULL; @@ -115,12 +138,29 @@ static int fail_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(NOTE_DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NOTE_END, ""); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -133,9 +173,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag("could not set core size: disallowed by hard limit"); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -201,53 +239,186 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel) { - va_list ap; + int testnumber; + int padding; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + testnumber = fail_count + success_count; + padding = TESTNAME_WIDTH; - if (logfile) - { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); - } + /* + * Calculate the width for the testname field required to align runtimes + * vertically. + */ + if (parallel) + padding -= PARALLEL_INDENT; + + /* + * There is no NLS translation here as "not ok" and "ok" are protocol. + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are indented 8 + * spaces in case they run as part of a parallel group. The position for + * the runtime is offset based on that indentation. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime); +#if 0 + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime); +#endif +} + +static void +test_status_ok(const char *testname, double runtime, bool parallel) +{ + success_count++; + + test_status_print(true, testname, runtime, parallel); } -/* - * Done "doing something ..." - */ static void -status_end(void) +test_status_failed(const char *testname, double runtime, bool parallel) { - fprintf(stdout, "\n"); - fflush(stdout); + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + fail_count++; + + test_status_print(false, testname, runtime, parallel); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); +} + +static void +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) +{ + va_list argp_logfile; + FILE *fp; + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * If we are ending a note_detail line we can avoid further processing and + * immediately return following a newline. + */ + if (type == NOTE_END) + { + in_note = false; + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + return; + } + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if ((type == NOTE || type == DIAG || type == BAIL) + || (type == NOTE_DETAIL && !in_note)) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If we are entering into a note with more details to follow, register + * that the leading '#' has been printed such that subsequent details + * aren't prefixed as well. + */ + if (type == NOTE_DETAIL) + in_note = true; + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail Out!"); + if (logfile) + fprintf(logfile, "Bail Out!"); + } + + va_end(argp_logfile); + + if (type != NOTE_DETAIL) + { + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + } + fflush(NULL); } /* @@ -271,9 +442,8 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d"), r); } postmaster_running = false; @@ -331,9 +501,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -455,9 +624,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -476,26 +644,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *expected++ = '\0'; @@ -741,13 +903,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note("using postmaster on %s, port %s", pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note("using postmaster on %s, default port", pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note("using postmaster on Unix socket, port %s", pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note("using postmaster on Unix socket, default port"); } load_resultmap(); @@ -796,35 +958,26 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not open process token: error code %lu", GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information buffer size: error code %lu", + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information: error code %lu", + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not look up account SID: error code %lu", + GetLastError()); } free(tokenuser); @@ -870,8 +1023,7 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) superuser_name = get_user_name(&errstr); if (superuser_name == NULL) { - fprintf(stderr, "%s: %s\n", progname, errstr); - exit(2); + bail("%s", errstr); } } @@ -902,9 +1054,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) do { \ if (!(cond)) \ { \ - fprintf(stderr, _("%s: could not write to file \"%s\": %s\n"), \ - progname, fname, strerror(errno)); \ - exit(2); \ + bail("could not write to file \"%s\": %s", \ + fname, strerror(errno)); \ } \ } while (0) @@ -915,15 +1066,13 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) * Truncating this name is a fatal error, because we must not fail to * overwrite an original trust-authentication pg_hba.conf. */ - fprintf(stderr, _("%s: directory name too long\n"), progname); - exit(2); + bail("directory name too long"); } hba = fopen(fname, "w"); if (hba == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", hba) >= 0); CW(fputs("host all all 127.0.0.1/32 sspi include_realm=1 map=regress\n", @@ -937,9 +1086,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) ident = fopen(fname, "w"); if (ident == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", ident) >= 0); @@ -973,7 +1121,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1029,8 +1177,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail("command failed: %s", buf->data); } /* Clean up */ @@ -1071,9 +1218,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail("could not fork: %s", strerror(errno)); } if (pid == 0) { @@ -1088,9 +1233,8 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit("could not exec \"%s\": %s", shellprog, strerror(errno)); } /* in parent */ return pid; @@ -1128,8 +1272,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1150,8 +1294,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1192,9 +1336,7 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", dir, strerror(errno)); } } @@ -1244,8 +1386,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail("diff command failed with status %d: %s", r, cmd); } #ifdef WIN32 @@ -1255,8 +1396,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail("diff command not found: %s", cmd); } #endif @@ -1327,9 +1467,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail("Unable to check secondary comparison files: %s", + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1444,9 +1583,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail("failed to wait for subprocesses: %s", strerror(errno)); } #else DWORD exit_status; @@ -1455,9 +1592,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail("failed to wait for subprocesses: error code %lu", + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1476,7 +1612,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1495,21 +1631,20 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag("(test process exited with exit code %d)", + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag("(test process was terminated by exception 0x%X)", + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag("(test process was terminated by signal %d: %s)", + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag("(test process exited with unrecognized status %d)", exitstatus); } /* @@ -1540,9 +1675,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1566,9 +1700,8 @@ run_schedule(const char *schedule, test_start_function startfunc, test = scbuf + 6; else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } num_tests = 0; @@ -1584,9 +1717,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1608,14 +1740,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1623,16 +1753,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note_detail("parallel group (%d tests, in groups of %d): ", + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1648,18 +1777,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note_detail("parallel group (%d tests): ", num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1670,8 +1799,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1692,36 +1820,27 @@ run_schedule(const char *schedule, test_start_function startfunc, newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } if (statuses[i] != 0) { - status(_("FAILED")); + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); log_child_failure(statuses[i]); - fail_count++; } else { - if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } } - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1756,7 +1875,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1780,35 +1898,29 @@ run_single_test(const char *test, test_start_function startfunc, newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (exit_status != 0) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); log_child_failure(exit_status); } else { if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); } } - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1830,9 +1942,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1841,9 +1952,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1859,7 +1969,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1876,7 +1985,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1898,10 +2006,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1909,7 +2014,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1921,7 +2025,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2143,8 +2246,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2164,9 +2267,7 @@ regression_main(int argc, char *argv[], */ if (!(dblist && dblist->str && dblist->str[0])) { - fprintf(stderr, _("%s: no database name was specified\n"), - progname); - exit(2); + bail("no database name was specified"); } if (config_auth_datadir) @@ -2217,17 +2318,12 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail("could not remove temp instance \"%s\"", temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2237,7 +2333,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2249,8 +2344,8 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail("initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s", + outputdir, buf); } /* @@ -2265,8 +2360,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail("could not open \"%s\" for adding extra config: %s", + buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2285,8 +2380,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail("could not open \"%s\" to read extra config: %s", + temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2325,14 +2420,13 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note("port %d apparently in use", port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note("could not determine an available port"); + bail("specify an unused port using the --port option or shut down any conflicting PostgreSQL servers."); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note("port %d apparently in use, trying %d", port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2344,7 +2438,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2356,11 +2449,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail("could not spawn postmaster: %s", strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2395,16 +2484,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail("postmaster failed, examine %s/log/postmaster.log for the reason", + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag("postmaster did not respond within %d seconds, examine %s/log/postmaster.log for the reason", + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2413,17 +2502,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail("could not kill failed postmaster: %s", strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail("could not kill failed postmaster: error code %lu", + GetLastError()); #endif - - exit(2); + bail("postmaster failed"); } postmaster_running = true; @@ -2434,8 +2520,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note("using temp instance on port %d with PID %lu", + port, ULONGPID(postmaster_pid)); } else { @@ -2466,8 +2552,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2483,7 +2567,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2494,49 +2577,45 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan(fail_count + success_count); /* * Emit nice-looking summary message */ if (fail_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); + note("All %d tests passed", success_count); else - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag("%d of %d tests failed", fail_count, success_count + fail_count); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag("The differences that caused some tests to fail can be viewed in the file \"%s\"", + difffilename); + diag("A copy of the test summary that you see above is saved in the file \"%s\"", + logfilename); } else { unlink(difffilename); unlink(logfilename); + + free(difffilename); + difffilename = NULL; + free(logfilename); + logfilename = NULL; } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.32.1 (Apple Git-133) ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-28 13:56 Daniel Gustafsson <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-03-28 13:56 UTC (permalink / raw) To: Peter Eisentraut <[email protected]>; +Cc: vignesh C <[email protected]>; Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> > On 28 Mar 2023, at 15:26, Daniel Gustafsson <[email protected]> wrote: > I think the attached is a good candidate for going in, but I would like to see it > for another spin in the CF bot first. Another candidate due to a thinko which raised a compiler warning. -- Daniel Gustafsson Attachments: [application/octet-stream] v19-0001-pg_regress-Emit-TAP-compliant-output.patch (40.0K, ../../[email protected]/2-v19-0001-pg_regress-Emit-TAP-compliant-output.patch) download | inline diff: From a5f76e7411dd4ae76553189829f86b4ee4a7417a Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Tue, 28 Mar 2023 15:20:19 +0200 Subject: [PATCH v19] pg_regress: Emit TAP compliant output MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This converts pg_regress output format to emit TAP compliant output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Reviewed-by: Andres Freund <[email protected]> Reviewed-by: Tom Lane <[email protected]> Reviewed-by: Nikolay Shaplov <[email protected]> Reviewed-by: Dagfinn Ilmari Mannsåker <[email protected]> Reviewed-by: Peter Eisentraut <[email protected]> Discussion: https://postgr.es/m/[email protected] Discussion: https://postgr.es/m/[email protected] --- meson.build | 1 + src/Makefile.global.in | 14 +- src/test/regress/pg_regress.c | 587 +++++++++++++++++++--------------- 3 files changed, 341 insertions(+), 261 deletions(-) diff --git a/meson.build b/meson.build index 61e94be864..dd23acee54 100644 --- a/meson.build +++ b/meson.build @@ -3118,6 +3118,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/Makefile.global.in b/src/Makefile.global.in index fb3e197fc0..9a7d41b727 100644 --- a/src/Makefile.global.in +++ b/src/Makefile.global.in @@ -444,7 +444,7 @@ ifeq ($(enable_tap_tests),yes) ifndef PGXS define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "\# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -457,7 +457,7 @@ cd $(srcdir) && \ endef else # PGXS case define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "\# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -471,7 +471,7 @@ endef endif # PGXS define prove_check -echo "+++ tap check in $(subdir) +++" && \ +echo "\# +++ tap check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -665,7 +665,7 @@ pg_regress_locale_flags = $(if $(ENCODING),--encoding=$(ENCODING)) $(NOLOCALE) pg_regress_clean_files = results/ regression.diffs regression.out tmp_check/ tmp_check_iso/ log/ output_iso/ pg_regress_check = \ - echo "+++ regress check in $(subdir) +++" && \ + echo "\# +++ regress check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/regress/pg_regress \ --temp-instance=./tmp_check \ @@ -674,14 +674,14 @@ pg_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_regress_installcheck = \ - echo "+++ regress install-check in $(subdir) +++" && \ + echo "\# +++ regress install-check in $(subdir) +++" && \ $(top_builddir)/src/test/regress/pg_regress \ --inputdir=$(srcdir) \ --bindir='$(bindir)' \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_check = \ - echo "+++ isolation check in $(subdir) +++" && \ + echo "\# +++ isolation check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --temp-instance=./tmp_check_iso \ @@ -690,7 +690,7 @@ pg_isolation_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_installcheck = \ - echo "+++ isolation install-check in $(subdir) +++" && \ + echo "\# +++ isolation install-check in $(subdir) +++" && \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --inputdir=$(srcdir) --outputdir=output_iso \ --bindir='$(bindir)' \ diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 7b23cc80dc..e98f06bea7 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,27 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* For parallel tests, testnames are indented when printed for grouping */ +#define PARALLEL_INDENT 3 +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + NOTE_DETAIL, + NOTE_END, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +124,8 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; +static bool in_note = false; static _resultmap *resultmap = NULL; @@ -115,12 +138,29 @@ static int fail_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(NOTE_DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NOTE_END, "\n"); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -133,9 +173,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag("could not set core size: disallowed by hard limit"); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -201,53 +239,186 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel) { - va_list ap; + int testnumber; + int padding; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + testnumber = fail_count + success_count; + padding = TESTNAME_WIDTH; - if (logfile) - { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); - } + /* + * Calculate the width for the testname field required to align runtimes + * vertically. + */ + if (parallel) + padding -= PARALLEL_INDENT; + + /* + * There is no NLS translation here as "not ok" and "ok" are protocol. + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are indented 8 + * spaces in case they run as part of a parallel group. The position for + * the runtime is offset based on that indentation. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime); +#if 0 + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %*s%-*s %8.0f ms", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* If parallel, indent to indicate grouping */ + (parallel ? PARALLEL_INDENT : 0), "", + /* Testnames are padded to align runtimes */ + padding, testname, + runtime); +#endif +} + +static void +test_status_ok(const char *testname, double runtime, bool parallel) +{ + success_count++; + + test_status_print(true, testname, runtime, parallel); } -/* - * Done "doing something ..." - */ static void -status_end(void) +test_status_failed(const char *testname, double runtime, bool parallel) { - fprintf(stdout, "\n"); - fflush(stdout); + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + fail_count++; + + test_status_print(false, testname, runtime, parallel); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); +} + +static void +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) +{ + va_list argp_logfile; + FILE *fp; + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * If we are ending a note_detail line we can avoid further processing and + * immediately return following a newline. + */ + if (type == NOTE_END) + { + in_note = false; + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + return; + } + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if ((type == NOTE || type == DIAG || type == BAIL) + || (type == NOTE_DETAIL && !in_note)) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If we are entering into a note with more details to follow, register + * that the leading '#' has been printed such that subsequent details + * aren't prefixed as well. + */ + if (type == NOTE_DETAIL) + in_note = true; + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail Out!"); + if (logfile) + fprintf(logfile, "Bail Out!"); + } + + va_end(argp_logfile); + + if (type != NOTE_DETAIL) + { + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + } + fflush(NULL); } /* @@ -271,9 +442,8 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d"), r); } postmaster_running = false; @@ -331,9 +501,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -455,9 +624,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -476,26 +644,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *expected++ = '\0'; @@ -741,13 +903,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note("using postmaster on %s, port %s", pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note("using postmaster on %s, default port", pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note("using postmaster on Unix socket, port %s", pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note("using postmaster on Unix socket, default port"); } load_resultmap(); @@ -796,35 +958,26 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not open process token: error code %lu", GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information buffer size: error code %lu", + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information: error code %lu", + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not look up account SID: error code %lu", + GetLastError()); } free(tokenuser); @@ -870,8 +1023,7 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) superuser_name = get_user_name(&errstr); if (superuser_name == NULL) { - fprintf(stderr, "%s: %s\n", progname, errstr); - exit(2); + bail("%s", errstr); } } @@ -902,9 +1054,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) do { \ if (!(cond)) \ { \ - fprintf(stderr, _("%s: could not write to file \"%s\": %s\n"), \ - progname, fname, strerror(errno)); \ - exit(2); \ + bail("could not write to file \"%s\": %s", \ + fname, strerror(errno)); \ } \ } while (0) @@ -915,15 +1066,13 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) * Truncating this name is a fatal error, because we must not fail to * overwrite an original trust-authentication pg_hba.conf. */ - fprintf(stderr, _("%s: directory name too long\n"), progname); - exit(2); + bail("directory name too long"); } hba = fopen(fname, "w"); if (hba == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", hba) >= 0); CW(fputs("host all all 127.0.0.1/32 sspi include_realm=1 map=regress\n", @@ -937,9 +1086,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) ident = fopen(fname, "w"); if (ident == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", ident) >= 0); @@ -973,7 +1121,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1029,8 +1177,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail("command failed: %s", buf->data); } /* Clean up */ @@ -1071,9 +1218,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail("could not fork: %s", strerror(errno)); } if (pid == 0) { @@ -1088,9 +1233,8 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit("could not exec \"%s\": %s", shellprog, strerror(errno)); } /* in parent */ return pid; @@ -1128,8 +1272,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1150,8 +1294,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1192,9 +1336,7 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", dir, strerror(errno)); } } @@ -1244,8 +1386,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail("diff command failed with status %d: %s", r, cmd); } #ifdef WIN32 @@ -1255,8 +1396,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail("diff command not found: %s", cmd); } #endif @@ -1327,9 +1467,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail("Unable to check secondary comparison files: %s", + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1444,9 +1583,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail("failed to wait for subprocesses: %s", strerror(errno)); } #else DWORD exit_status; @@ -1455,9 +1592,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail("failed to wait for subprocesses: error code %lu", + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1476,7 +1612,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1495,21 +1631,20 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag("(test process exited with exit code %d)", + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag("(test process was terminated by exception 0x%X)", + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag("(test process was terminated by signal %d: %s)", + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag("(test process exited with unrecognized status %d)", exitstatus); } /* @@ -1540,9 +1675,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1566,9 +1700,8 @@ run_schedule(const char *schedule, test_start_function startfunc, test = scbuf + 6; else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } num_tests = 0; @@ -1584,9 +1717,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1608,14 +1740,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1623,16 +1753,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note_detail("parallel group (%d tests, in groups of %d): ", + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1648,18 +1777,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note_detail("parallel group (%d tests): ", num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1670,8 +1799,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1692,36 +1820,27 @@ run_schedule(const char *schedule, test_start_function startfunc, newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } if (statuses[i] != 0) { - status(_("FAILED")); + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); log_child_failure(statuses[i]); - fail_count++; } else { - if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } } - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1756,7 +1875,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1780,35 +1898,29 @@ run_single_test(const char *test, test_start_function startfunc, newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (exit_status != 0) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); log_child_failure(exit_status); } else { if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); } } - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1830,9 +1942,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1841,9 +1952,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1859,7 +1969,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1876,7 +1985,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1898,10 +2006,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1909,7 +2014,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1921,7 +2025,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2143,8 +2246,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2164,9 +2267,7 @@ regression_main(int argc, char *argv[], */ if (!(dblist && dblist->str && dblist->str[0])) { - fprintf(stderr, _("%s: no database name was specified\n"), - progname); - exit(2); + bail("no database name was specified"); } if (config_auth_datadir) @@ -2217,17 +2318,12 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail("could not remove temp instance \"%s\"", temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2237,7 +2333,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2249,8 +2344,8 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail("initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s", + outputdir, buf); } /* @@ -2265,8 +2360,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail("could not open \"%s\" for adding extra config: %s", + buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2285,8 +2380,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail("could not open \"%s\" to read extra config: %s", + temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2325,14 +2420,13 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note("port %d apparently in use", port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note("could not determine an available port"); + bail("specify an unused port using the --port option or shut down any conflicting PostgreSQL servers."); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note("port %d apparently in use, trying %d", port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2344,7 +2438,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2356,11 +2449,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail("could not spawn postmaster: %s", strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2395,16 +2484,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail("postmaster failed, examine %s/log/postmaster.log for the reason", + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag("postmaster did not respond within %d seconds, examine %s/log/postmaster.log for the reason", + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2413,17 +2502,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail("could not kill failed postmaster: %s", strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail("could not kill failed postmaster: error code %lu", + GetLastError()); #endif - - exit(2); + bail("postmaster failed"); } postmaster_running = true; @@ -2434,8 +2520,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note("using temp instance on port %d with PID %lu", + port, ULONGPID(postmaster_pid)); } else { @@ -2466,8 +2552,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2483,7 +2567,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2494,49 +2577,45 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan(fail_count + success_count); /* * Emit nice-looking summary message */ if (fail_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); + note("All %d tests passed", success_count); else - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag("%d of %d tests failed", fail_count, success_count + fail_count); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag("The differences that caused some tests to fail can be viewed in the file \"%s\"", + difffilename); + diag("A copy of the test summary that you see above is saved in the file \"%s\"", + logfilename); } else { unlink(difffilename); unlink(logfilename); + + free(difffilename); + difffilename = NULL; + free(logfilename); + logfilename = NULL; } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.32.1 (Apple Git-133) ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-29 07:08 Peter Eisentraut <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Peter Eisentraut @ 2023-03-29 07:08 UTC (permalink / raw) To: Daniel Gustafsson <[email protected]>; +Cc: vignesh C <[email protected]>; Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> On 28.03.23 15:56, Daniel Gustafsson wrote: >> On 28 Mar 2023, at 15:26, Daniel Gustafsson <[email protected]> wrote: > >> I think the attached is a good candidate for going in, but I would like to see it >> for another spin in the CF bot first. > > Another candidate due to a thinko which raised a compiler warning. This is incorrect: -echo "+++ tap install-check in $(subdir) +++" && \ +echo "\# +++ tap install-check in $(subdir) +++" && \ It actually prints the backslash. But this appears to be correct: pg_regress_check = \ - echo "+++ regress check in $(subdir) +++" && \ + echo "\# +++ regress check in $(subdir) +++" && \ (Maybe because it's in a variable definition?) I'm confused why all the messages at the end lost their period ("All tests passed", "A copy of the test summary ...", etc.). As long as they are written as sentences, they should have a period. There is a comment "Testnames are indented 8 spaces" but you made that into a macro now, which is currently defined to 3. There is an unexplained #if 0. The additions of + free(difffilename); + difffilename = NULL; + free(logfilename); + logfilename = NULL; in the success case are not clear. The program is going to end soon anyway. On the indentation of the test names: If you look at the output of meson test verbose mode (e.g., meson test -C _build --suite regress --verbose), it reproduces the indentation in a weirdly backwards way, e.g., ▶ 1/1 stats 981 ms OK ▶ 1/1 event_trigger 122 ms OK ▶ 1/1 oidjoins 172 ms OK ▶ 1/1 fast_default 137 ms OK ▶ 1/1 tablespace 285 ms OK Not sure by which logic it arrives at that, but you can clearly see 3 additional spaces for the single tests. One thing I have noticed while playing around with this is that it's quite hard to tell casually whether a test run has failed or is failing, if you just keep half an eye on it in another Window. The display of "ok"/"not ok" as well as the summaries at the end are much less prominent than the previous "ok"/"FAILED" and the summary box at the end. I'm not sure what to do about that, or if it's just something to get used to. ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-29 19:14 Daniel Gustafsson <[email protected]> parent: Peter Eisentraut <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-03-29 19:14 UTC (permalink / raw) To: Peter Eisentraut <[email protected]>; +Cc: vignesh C <[email protected]>; Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> > On 29 Mar 2023, at 09:08, Peter Eisentraut <[email protected]> wrote: > > On 28.03.23 15:56, Daniel Gustafsson wrote: >>> On 28 Mar 2023, at 15:26, Daniel Gustafsson <[email protected]> wrote: >>> I think the attached is a good candidate for going in, but I would like to see it >>> for another spin in the CF bot first. >> Another candidate due to a thinko which raised a compiler warning. > > This is incorrect: > > -echo "+++ tap install-check in $(subdir) +++" && \ > +echo "\# +++ tap install-check in $(subdir) +++" && \ > > It actually prints the backslash. > > But this appears to be correct: > > pg_regress_check = \ > - echo "+++ regress check in $(subdir) +++" && \ > + echo "\# +++ regress check in $(subdir) +++" && \ > > (Maybe because it's in a variable definition?) Copy paste error, fixed. > I'm confused why all the messages at the end lost their period ("All tests passed", "A copy of the test summary ...", etc.). As long as they are written as sentences, they should have a period. Fixed. I also made sure that all messages printing the output directory wrap it in quotes like how we print paths generally. > There is a comment "Testnames are indented 8 spaces" but you made that into a macro now, which is currently defined to 3. As explained below, this is removed. I've also removed a comment on NLS which no longer makes sense. > There is an unexplained #if 0. Ugh, I clearly should've stayed on the couch yesterday. > The additions of > > + free(difffilename); > + difffilename = NULL; > + free(logfilename); > + logfilename = NULL; > > in the success case are not clear. The program is going to end soon anyway. Fair enough, removed. > On the indentation of the test names: If you look at the output of meson test verbose mode (e.g., meson test -C _build --suite regress --verbose), it reproduces the indentation in a weirdly backwards way, e.g., > > ▶ 1/1 stats 981 ms OK > ▶ 1/1 event_trigger 122 ms OK > ▶ 1/1 oidjoins 172 ms OK > ▶ 1/1 fast_default 137 ms OK > ▶ 1/1 tablespace 285 ms OK > > Not sure by which logic it arrives at that, but you can clearly see 3 additional spaces for the single tests. I'm not sure what meson does actually. It seems to strip the leading padding and line up the testname, but then add the stripped padding on the right side? Removing the padding for parallel tests solves it, so I have in the attached moved to indicating parallel tests with a leading '+' and single tests with '-'. Not sure if this is clear enough, but it's not worse than padding IMO. > One thing I have noticed while playing around with this is that it's quite hard to tell casually whether a test run has failed or is failing, if you just keep half an eye on it in another Window. The display of "ok"/"not ok" as well as the summaries at the end are much less prominent than the previous "ok"/"FAILED" and the summary box at the end. I'm not sure what to do about that, or if it's just something to get used to. meson already presents the results in a box, so if we bring back the === box it gets quite verbose there. To some extent I think it is something to get used to, but if there is discontent with what it looks like reported when more hackers gets exposed to this we need to fix it. -- Daniel Gustafsson Attachments: [application/octet-stream] v20-0001-pg_regress-Emit-TAP-compliant-output.patch (39.3K, ../../[email protected]/2-v20-0001-pg_regress-Emit-TAP-compliant-output.patch) download | inline diff: From 786750d6e6ccddade942c6df2abb5eef41c17aba Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Tue, 28 Mar 2023 15:20:19 +0200 Subject: [PATCH v20] pg_regress: Emit TAP compliant output MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This converts pg_regress output format to emit TAP compliant output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Reviewed-by: Andres Freund <[email protected]> Reviewed-by: Tom Lane <[email protected]> Reviewed-by: Nikolay Shaplov <[email protected]> Reviewed-by: Dagfinn Ilmari Mannsåker <[email protected]> Reviewed-by: Peter Eisentraut <[email protected]> Discussion: https://postgr.es/m/[email protected] Discussion: https://postgr.es/m/[email protected] --- meson.build | 1 + src/Makefile.global.in | 14 +- src/test/regress/pg_regress.c | 558 ++++++++++++++++++---------------- 3 files changed, 312 insertions(+), 261 deletions(-) diff --git a/meson.build b/meson.build index 61e94be864..dd23acee54 100644 --- a/meson.build +++ b/meson.build @@ -3118,6 +3118,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/Makefile.global.in b/src/Makefile.global.in index fb3e197fc0..736dd1ed5e 100644 --- a/src/Makefile.global.in +++ b/src/Makefile.global.in @@ -444,7 +444,7 @@ ifeq ($(enable_tap_tests),yes) ifndef PGXS define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -457,7 +457,7 @@ cd $(srcdir) && \ endef else # PGXS case define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -471,7 +471,7 @@ endef endif # PGXS define prove_check -echo "+++ tap check in $(subdir) +++" && \ +echo "# +++ tap check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -665,7 +665,7 @@ pg_regress_locale_flags = $(if $(ENCODING),--encoding=$(ENCODING)) $(NOLOCALE) pg_regress_clean_files = results/ regression.diffs regression.out tmp_check/ tmp_check_iso/ log/ output_iso/ pg_regress_check = \ - echo "+++ regress check in $(subdir) +++" && \ + echo "\# +++ regress check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/regress/pg_regress \ --temp-instance=./tmp_check \ @@ -674,14 +674,14 @@ pg_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_regress_installcheck = \ - echo "+++ regress install-check in $(subdir) +++" && \ + echo "\# +++ regress install-check in $(subdir) +++" && \ $(top_builddir)/src/test/regress/pg_regress \ --inputdir=$(srcdir) \ --bindir='$(bindir)' \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_check = \ - echo "+++ isolation check in $(subdir) +++" && \ + echo "\# +++ isolation check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --temp-instance=./tmp_check_iso \ @@ -690,7 +690,7 @@ pg_isolation_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_installcheck = \ - echo "+++ isolation install-check in $(subdir) +++" && \ + echo "\# +++ isolation install-check in $(subdir) +++" && \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --inputdir=$(srcdir) --outputdir=output_iso \ --bindir='$(bindir)' \ diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 7b23cc80dc..7c642519b6 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,25 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + NOTE_DETAIL, + NOTE_END, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +122,8 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; +static bool in_note = false; static _resultmap *resultmap = NULL; @@ -115,12 +136,29 @@ static int fail_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(NOTE_DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NOTE_END, "\n"); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -133,9 +171,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag("could not set core size: disallowed by hard limit"); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -201,53 +237,162 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel) { - va_list ap; + int testnumber = fail_count + success_count; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + /* + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are prefixed with + * a leading character to indicate being run in parallel or not. A leading + * '+' indicates a parellel test, '-' indicates a single test. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %c %-*s %8.0f ms", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* Prefix a parallel test '+' and a single test with '-' */ + (parallel ? '+' : '-'), + /* Testnames are padded to align runtimes */ + TESTNAME_WIDTH, testname, + runtime); +} - if (logfile) - { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); - } +static void +test_status_ok(const char *testname, double runtime, bool parallel) +{ + success_count++; + + test_status_print(true, testname, runtime, parallel); } -/* - * Done "doing something ..." - */ static void -status_end(void) +test_status_failed(const char *testname, double runtime, bool parallel) { - fprintf(stdout, "\n"); - fflush(stdout); + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + fail_count++; + + test_status_print(false, testname, runtime, parallel); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); +} + +static void +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) +{ + va_list argp_logfile; + FILE *fp; + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * If we are ending a note_detail line we can avoid further processing and + * immediately return following a newline. + */ + if (type == NOTE_END) + { + in_note = false; + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + return; + } + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if ((type == NOTE || type == DIAG || type == BAIL) + || (type == NOTE_DETAIL && !in_note)) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If we are entering into a note with more details to follow, register + * that the leading '#' has been printed such that subsequent details + * aren't prefixed as well. + */ + if (type == NOTE_DETAIL) + in_note = true; + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail out!"); + if (logfile) + fprintf(logfile, "Bail out!"); + } + + va_end(argp_logfile); + + if (type != NOTE_DETAIL) + { + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + } + fflush(NULL); } /* @@ -271,9 +416,8 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d"), r); } postmaster_running = false; @@ -331,9 +475,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -455,9 +598,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -476,26 +618,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *expected++ = '\0'; @@ -741,13 +877,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note("using postmaster on %s, port %s", pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note("using postmaster on %s, default port", pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note("using postmaster on Unix socket, port %s", pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note("using postmaster on Unix socket, default port"); } load_resultmap(); @@ -796,35 +932,26 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not open process token: error code %lu", GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information buffer size: error code %lu", + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information: error code %lu", + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not look up account SID: error code %lu", + GetLastError()); } free(tokenuser); @@ -870,8 +997,7 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) superuser_name = get_user_name(&errstr); if (superuser_name == NULL) { - fprintf(stderr, "%s: %s\n", progname, errstr); - exit(2); + bail("%s", errstr); } } @@ -902,9 +1028,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) do { \ if (!(cond)) \ { \ - fprintf(stderr, _("%s: could not write to file \"%s\": %s\n"), \ - progname, fname, strerror(errno)); \ - exit(2); \ + bail("could not write to file \"%s\": %s", \ + fname, strerror(errno)); \ } \ } while (0) @@ -915,15 +1040,13 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) * Truncating this name is a fatal error, because we must not fail to * overwrite an original trust-authentication pg_hba.conf. */ - fprintf(stderr, _("%s: directory name too long\n"), progname); - exit(2); + bail("directory name too long"); } hba = fopen(fname, "w"); if (hba == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", hba) >= 0); CW(fputs("host all all 127.0.0.1/32 sspi include_realm=1 map=regress\n", @@ -937,9 +1060,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) ident = fopen(fname, "w"); if (ident == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", ident) >= 0); @@ -973,7 +1095,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1029,8 +1151,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail("command failed: %s", buf->data); } /* Clean up */ @@ -1071,9 +1192,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail("could not fork: %s", strerror(errno)); } if (pid == 0) { @@ -1088,9 +1207,8 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit("could not exec \"%s\": %s", shellprog, strerror(errno)); } /* in parent */ return pid; @@ -1128,8 +1246,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1150,8 +1268,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1192,9 +1310,7 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", dir, strerror(errno)); } } @@ -1244,8 +1360,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail("diff command failed with status %d: %s", r, cmd); } #ifdef WIN32 @@ -1255,8 +1370,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail("diff command not found: %s", cmd); } #endif @@ -1327,9 +1441,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail("Unable to check secondary comparison files: %s", + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1444,9 +1557,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail("failed to wait for subprocesses: %s", strerror(errno)); } #else DWORD exit_status; @@ -1455,9 +1566,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail("failed to wait for subprocesses: error code %lu", + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1476,7 +1586,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1495,21 +1605,20 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag("(test process exited with exit code %d)", + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag("(test process was terminated by exception 0x%X)", + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag("(test process was terminated by signal %d: %s)", + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag("(test process exited with unrecognized status %d)", exitstatus); } /* @@ -1540,9 +1649,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1566,9 +1674,8 @@ run_schedule(const char *schedule, test_start_function startfunc, test = scbuf + 6; else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } num_tests = 0; @@ -1584,9 +1691,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1608,14 +1714,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1623,16 +1727,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note_detail("parallel group (%d tests, in groups of %d): ", + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1648,18 +1751,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note_detail("parallel group (%d tests): ", num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1670,8 +1773,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1692,36 +1794,27 @@ run_schedule(const char *schedule, test_start_function startfunc, newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } if (statuses[i] != 0) { - status(_("FAILED")); + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); log_child_failure(statuses[i]); - fail_count++; } else { - if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } } - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1756,7 +1849,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1780,35 +1872,29 @@ run_single_test(const char *test, test_start_function startfunc, newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (exit_status != 0) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); log_child_failure(exit_status); } else { if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); } } - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1830,9 +1916,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1841,9 +1926,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1859,7 +1943,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1876,7 +1959,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1898,10 +1980,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1909,7 +1988,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1921,7 +1999,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2143,8 +2220,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2164,9 +2241,7 @@ regression_main(int argc, char *argv[], */ if (!(dblist && dblist->str && dblist->str[0])) { - fprintf(stderr, _("%s: no database name was specified\n"), - progname); - exit(2); + bail("no database name was specified"); } if (config_auth_datadir) @@ -2217,17 +2292,12 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail("could not remove temp instance \"%s\"", temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2237,7 +2307,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2249,8 +2318,10 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail("initdb failed\n" + "# Examine \"%s/log/initdb.log\" for the reason.\n" + "# Command was: %s", + outputdir, buf); } /* @@ -2265,8 +2336,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail("could not open \"%s\" for adding extra config: %s", + buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2285,8 +2356,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail("could not open \"%s\" to read extra config: %s", + temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2325,14 +2396,13 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note("port %d apparently in use", port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note("could not determine an available port"); + bail("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers."); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note("port %d apparently in use, trying %d", port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2344,7 +2414,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2356,11 +2425,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail("could not spawn postmaster: %s", strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2395,16 +2460,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail("postmaster failed, examine \"%s/log/postmaster.log\" for the reason", + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag("postmaster did not respond within %d seconds, examine \"%s/log/postmaster.log\" for the reason", + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2413,17 +2478,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail("could not kill failed postmaster: %s", strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail("could not kill failed postmaster: error code %lu", + GetLastError()); #endif - - exit(2); + bail("postmaster failed"); } postmaster_running = true; @@ -2434,8 +2496,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note("using temp instance on port %d with PID %lu", + port, ULONGPID(postmaster_pid)); } else { @@ -2466,8 +2528,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2483,7 +2543,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2494,42 +2553,30 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan(fail_count + success_count); /* * Emit nice-looking summary message */ if (fail_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); + note("All %d tests passed.", success_count); else - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag("%d of %d tests failed.", fail_count, success_count + fail_count); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag("The differences that caused some tests to fail can be viewed in the file \"%s\".", + difffilename); + diag("A copy of the test summary that you see above is saved in the file \"%s\".", + logfilename); } else { @@ -2537,6 +2584,9 @@ regression_main(int argc, char *argv[], unlink(logfilename); } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.32.1 (Apple Git-133) ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-29 20:08 Daniel Gustafsson <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 1 reply; 14+ messages in thread From: Daniel Gustafsson @ 2023-03-29 20:08 UTC (permalink / raw) To: Peter Eisentraut <[email protected]>; +Cc: vignesh C <[email protected]>; Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> > On 29 Mar 2023, at 21:14, Daniel Gustafsson <[email protected]> wrote: > Ugh, I clearly should've stayed on the couch yesterday. Maybe today as well, just as I had sent this I realized there is mention of the output format in the docs that I had missed. The attached changes that as well to match the new format. (The section in question doesn't mention using meson, but I have a feeling that's tackled in one of the meson docs threads.) -- Daniel Gustafsson Attachments: [application/octet-stream] v21-0001-pg_regress-Emit-TAP-compliant-output.patch (39.8K, ../../[email protected]/2-v21-0001-pg_regress-Emit-TAP-compliant-output.patch) download | inline diff: From 2f08bcabc93d498494b444234e5c5a7a13f46a49 Mon Sep 17 00:00:00 2001 From: Daniel Gustafsson <[email protected]> Date: Tue, 28 Mar 2023 15:20:19 +0200 Subject: [PATCH v21] pg_regress: Emit TAP compliant output MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This converts pg_regress output format to emit TAP compliant output while keeping it as human readable as possible for use without TAP test harnesses. As verbose harness related information isn't really supported by TAP this also reduces the verbosity of pg_regress runs which makes scrolling through log output in buildfarm/CI runs a bit easier as well. TAP format testing is also enabled in Meson as of this. Reviewed-by: Andres Freund <[email protected]> Reviewed-by: Tom Lane <[email protected]> Reviewed-by: Nikolay Shaplov <[email protected]> Reviewed-by: Dagfinn Ilmari Mannsåker <[email protected]> Reviewed-by: Peter Eisentraut <[email protected]> Discussion: https://postgr.es/m/[email protected] Discussion: https://postgr.es/m/[email protected] --- doc/src/sgml/regress.sgml | 4 +- meson.build | 1 + src/Makefile.global.in | 14 +- src/test/regress/pg_regress.c | 558 ++++++++++++++++++---------------- 4 files changed, 313 insertions(+), 264 deletions(-) diff --git a/doc/src/sgml/regress.sgml b/doc/src/sgml/regress.sgml index 719e0a7698..e7616e689d 100644 --- a/doc/src/sgml/regress.sgml +++ b/doc/src/sgml/regress.sgml @@ -46,9 +46,7 @@ make check At the end you should see something like: <screen> <computeroutput> -======================= - All 193 tests passed. -======================= +# All 213 tests passed. </computeroutput> </screen> or otherwise a note about which tests failed. See <xref diff --git a/meson.build b/meson.build index 61e94be864..dd23acee54 100644 --- a/meson.build +++ b/meson.build @@ -3118,6 +3118,7 @@ foreach test_dir : tests env.prepend('PATH', temp_install_bindir, test_dir['bd']) test_kwargs = { + 'protocol': 'tap', 'priority': 10, 'timeout': 1000, 'depends': test_deps + t.get('deps', []), diff --git a/src/Makefile.global.in b/src/Makefile.global.in index fb3e197fc0..736dd1ed5e 100644 --- a/src/Makefile.global.in +++ b/src/Makefile.global.in @@ -444,7 +444,7 @@ ifeq ($(enable_tap_tests),yes) ifndef PGXS define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -457,7 +457,7 @@ cd $(srcdir) && \ endef else # PGXS case define prove_installcheck -echo "+++ tap install-check in $(subdir) +++" && \ +echo "# +++ tap install-check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -471,7 +471,7 @@ endef endif # PGXS define prove_check -echo "+++ tap check in $(subdir) +++" && \ +echo "# +++ tap check in $(subdir) +++" && \ rm -rf '$(CURDIR)'/tmp_check && \ $(MKDIR_P) '$(CURDIR)'/tmp_check && \ cd $(srcdir) && \ @@ -665,7 +665,7 @@ pg_regress_locale_flags = $(if $(ENCODING),--encoding=$(ENCODING)) $(NOLOCALE) pg_regress_clean_files = results/ regression.diffs regression.out tmp_check/ tmp_check_iso/ log/ output_iso/ pg_regress_check = \ - echo "+++ regress check in $(subdir) +++" && \ + echo "\# +++ regress check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/regress/pg_regress \ --temp-instance=./tmp_check \ @@ -674,14 +674,14 @@ pg_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_regress_installcheck = \ - echo "+++ regress install-check in $(subdir) +++" && \ + echo "\# +++ regress install-check in $(subdir) +++" && \ $(top_builddir)/src/test/regress/pg_regress \ --inputdir=$(srcdir) \ --bindir='$(bindir)' \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_check = \ - echo "+++ isolation check in $(subdir) +++" && \ + echo "\# +++ isolation check in $(subdir) +++" && \ $(with_temp_install) \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --temp-instance=./tmp_check_iso \ @@ -690,7 +690,7 @@ pg_isolation_regress_check = \ $(TEMP_CONF) \ $(pg_regress_locale_flags) $(EXTRA_REGRESS_OPTS) pg_isolation_regress_installcheck = \ - echo "+++ isolation install-check in $(subdir) +++" && \ + echo "\# +++ isolation install-check in $(subdir) +++" && \ $(top_builddir)/src/test/isolation/pg_isolation_regress \ --inputdir=$(srcdir) --outputdir=output_iso \ --bindir='$(bindir)' \ diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 7b23cc80dc..7c642519b6 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -68,6 +68,25 @@ const char *basic_diff_opts = "-w"; const char *pretty_diff_opts = "-w -U3"; #endif +/* + * The width of the testname field when printing to ensure vertical alignment + * of test runtimes. This number is somewhat arbitrarily chosen to match the + * older pre-TAP output format. + */ +#define TESTNAME_WIDTH 36 + +typedef enum TAPtype +{ + DIAG = 0, + BAIL, + NOTE, + NOTE_DETAIL, + NOTE_END, + TEST_STATUS, + PLAN, + NONE +} TAPtype; + /* options settable from command line */ _stringlist *dblist = NULL; bool debug = false; @@ -103,6 +122,8 @@ static const char *sockdir; static const char *temp_sockdir; static char sockself[MAXPGPATH]; static char socklock[MAXPGPATH]; +static StringInfo failed_tests = NULL; +static bool in_note = false; static _resultmap *resultmap = NULL; @@ -115,12 +136,29 @@ static int fail_count = 0; static bool directory_exists(const char *dir); static void make_directory(const char *dir); -static void header(const char *fmt,...) pg_attribute_printf(1, 2); -static void status(const char *fmt,...) pg_attribute_printf(1, 2); +static void test_status_print(bool ok, const char *testname, double runtime, bool parallel); +static void test_status_ok(const char *testname, double runtime, bool parallel); +static void test_status_failed(const char *testname, double runtime, bool parallel); +static void bail_out(bool noatexit, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output(TAPtype type, const char *fmt,...) pg_attribute_printf(2, 3); +static void emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) pg_attribute_printf(2, 0); + static StringInfo psql_start_command(void); static void psql_add_command(StringInfo buf, const char *query,...) pg_attribute_printf(2, 3); static void psql_end_command(StringInfo buf, const char *database); +/* + * Convenience macros for printing TAP output with a more shorthand syntax + * aimed at making the code more readable. + */ +#define plan(x) emit_tap_output(PLAN, "1..%i", (x)) +#define note(...) emit_tap_output(NOTE, __VA_ARGS__) +#define note_detail(...) emit_tap_output(NOTE_DETAIL, __VA_ARGS__) +#define diag(...) emit_tap_output(DIAG, __VA_ARGS__) +#define note_end() emit_tap_output(NOTE_END, "\n"); +#define bail_noatexit(...) bail_out(true, __VA_ARGS__) +#define bail(...) bail_out(false, __VA_ARGS__) + /* * allow core files if possible. */ @@ -133,9 +171,7 @@ unlimit_core_size(void) getrlimit(RLIMIT_CORE, &lim); if (lim.rlim_max == 0) { - fprintf(stderr, - _("%s: could not set core size: disallowed by hard limit\n"), - progname); + diag("could not set core size: disallowed by hard limit"); return; } else if (lim.rlim_max == RLIM_INFINITY || lim.rlim_cur < lim.rlim_max) @@ -201,53 +237,162 @@ split_to_stringlist(const char *s, const char *delim, _stringlist **listhead) } /* - * Print a progress banner on stdout. + * Bailing out is for unrecoverable errors which prevents further testing to + * occur and after which the test run should be aborted. By passing noatexit + * as true the process will terminate with _exit(2) and skipping registered + * exit handlers, thus avoid any risk of bottomless recursion calls to exit. */ static void -header(const char *fmt,...) +bail_out(bool noatexit, const char *fmt,...) { - char tmp[64]; va_list ap; va_start(ap, fmt); - vsnprintf(tmp, sizeof(tmp), fmt, ap); + emit_tap_output_v(BAIL, fmt, ap); va_end(ap); - fprintf(stdout, "============== %-38s ==============\n", tmp); - fflush(stdout); + if (noatexit) + _exit(2); + + exit(2); } -/* - * Print "doing something ..." --- supplied text should not end with newline - */ static void -status(const char *fmt,...) +test_status_print(bool ok, const char *testname, double runtime, bool parallel) { - va_list ap; + int testnumber = fail_count + success_count; - va_start(ap, fmt); - vfprintf(stdout, fmt, ap); - fflush(stdout); - va_end(ap); + /* + * Testnumbers are padded to 5 characters to ensure that testnames align + * vertically (assuming at most 9999 tests). Testnames are prefixed with + * a leading character to indicate being run in parallel or not. A leading + * '+' indicates a parellel test, '-' indicates a single test. + */ + emit_tap_output(TEST_STATUS, "%sok %-5i%*s %c %-*s %8.0f ms", + (ok ? "" : "not "), + testnumber, + /* If ok, indent with four spaces matching "not " */ + (ok ? (int) strlen("not ") : 0), "", + /* Prefix a parallel test '+' and a single test with '-' */ + (parallel ? '+' : '-'), + /* Testnames are padded to align runtimes */ + TESTNAME_WIDTH, testname, + runtime); +} - if (logfile) - { - va_start(ap, fmt); - vfprintf(logfile, fmt, ap); - va_end(ap); - } +static void +test_status_ok(const char *testname, double runtime, bool parallel) +{ + success_count++; + + test_status_print(true, testname, runtime, parallel); } -/* - * Done "doing something ..." - */ static void -status_end(void) +test_status_failed(const char *testname, double runtime, bool parallel) { - fprintf(stdout, "\n"); - fflush(stdout); + /* + * Save failed tests in a buffer such that we can print a summary at the + * end with diag() to ensure it's shown even under test harnesses. + */ + if (!failed_tests) + failed_tests = makeStringInfo(); + else + appendStringInfoChar(failed_tests, ','); + + appendStringInfo(failed_tests, " %s", testname); + + fail_count++; + + test_status_print(false, testname, runtime, parallel); +} + + +static void +emit_tap_output(TAPtype type, const char *fmt,...) +{ + va_list argp; + + va_start(argp, fmt); + emit_tap_output_v(type, fmt, argp); + va_end(argp); +} + +static void +emit_tap_output_v(TAPtype type, const char *fmt, va_list argp) +{ + va_list argp_logfile; + FILE *fp; + + /* + * Diagnostic output will be hidden by prove unless printed to stderr. The + * Bail message is also printed to stderr to aid debugging under a harness + * which might otherwise not emit such an important message. + */ + if (type == DIAG || type == BAIL) + fp = stderr; + else + fp = stdout; + + /* + * If we are ending a note_detail line we can avoid further processing and + * immediately return following a newline. + */ + if (type == NOTE_END) + { + in_note = false; + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + return; + } + + /* Make a copy of the va args for printing to the logfile */ + va_copy(argp_logfile, argp); + + /* + * Non-protocol output such as diagnostics or notes must be prefixed by a + * '#' character. We print the Bail message like this too. + */ + if ((type == NOTE || type == DIAG || type == BAIL) + || (type == NOTE_DETAIL && !in_note)) + { + fprintf(fp, "# "); + if (logfile) + fprintf(logfile, "# "); + } + vfprintf(fp, fmt, argp); if (logfile) - fprintf(logfile, "\n"); + vfprintf(logfile, fmt, argp_logfile); + + /* + * If we are entering into a note with more details to follow, register + * that the leading '#' has been printed such that subsequent details + * aren't prefixed as well. + */ + if (type == NOTE_DETAIL) + in_note = true; + + /* + * If this was a Bail message, the bail protocol message must go to stdout + * separately. + */ + if (type == BAIL) + { + fprintf(stdout, "Bail out!"); + if (logfile) + fprintf(logfile, "Bail out!"); + } + + va_end(argp_logfile); + + if (type != NOTE_DETAIL) + { + fprintf(fp, "\n"); + if (logfile) + fprintf(logfile, "\n"); + } + fflush(NULL); } /* @@ -271,9 +416,8 @@ stop_postmaster(void) r = system(buf); if (r != 0) { - fprintf(stderr, _("\n%s: could not stop postmaster: exit code was %d\n"), - progname, r); - _exit(2); /* not exit(), that could be recursive */ + /* Not using the normal bail() as we want _exit */ + bail_noatexit(_("could not stop postmaster: exit code was %d"), r); } postmaster_running = false; @@ -331,9 +475,8 @@ make_temp_sockdir(void) temp_sockdir = mkdtemp(template); if (temp_sockdir == NULL) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, template, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", + template, strerror(errno)); } /* Stage file names for remove_temp(). Unsafe in a signal handler. */ @@ -455,9 +598,8 @@ load_resultmap(void) /* OK if it doesn't exist, else complain */ if (errno == ENOENT) return; - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, buf, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + buf, strerror(errno)); } while (fgets(buf, sizeof(buf), f)) @@ -476,26 +618,20 @@ load_resultmap(void) file_type = strchr(buf, ':'); if (!file_type) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *file_type++ = '\0'; platform = strchr(file_type, ':'); if (!platform) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *platform++ = '\0'; expected = strchr(platform, '='); if (!expected) { - fprintf(stderr, _("incorrectly formatted resultmap entry: %s\n"), - buf); - exit(2); + bail("incorrectly formatted resultmap entry: %s", buf); } *expected++ = '\0'; @@ -741,13 +877,13 @@ initialize_environment(void) } if (pghost && pgport) - printf(_("(using postmaster on %s, port %s)\n"), pghost, pgport); + note("using postmaster on %s, port %s", pghost, pgport); if (pghost && !pgport) - printf(_("(using postmaster on %s, default port)\n"), pghost); + note("using postmaster on %s, default port", pghost); if (!pghost && pgport) - printf(_("(using postmaster on Unix socket, port %s)\n"), pgport); + note("using postmaster on Unix socket, port %s", pgport); if (!pghost && !pgport) - printf(_("(using postmaster on Unix socket, default port)\n")); + note("using postmaster on Unix socket, default port"); } load_resultmap(); @@ -796,35 +932,26 @@ current_windows_user(const char **acct, const char **dom) if (!OpenProcessToken(GetCurrentProcess(), TOKEN_READ, &token)) { - fprintf(stderr, - _("%s: could not open process token: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not open process token: error code %lu", GetLastError()); } if (!GetTokenInformation(token, TokenUser, NULL, 0, &retlen) && GetLastError() != 122) { - fprintf(stderr, - _("%s: could not get token information buffer size: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information buffer size: error code %lu", + GetLastError()); } tokenuser = pg_malloc(retlen); if (!GetTokenInformation(token, TokenUser, tokenuser, retlen, &retlen)) { - fprintf(stderr, - _("%s: could not get token information: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not get token information: error code %lu", + GetLastError()); } if (!LookupAccountSid(NULL, tokenuser->User.Sid, accountname, &accountnamesize, domainname, &domainnamesize, &accountnameuse)) { - fprintf(stderr, - _("%s: could not look up account SID: error code %lu\n"), - progname, GetLastError()); - exit(2); + bail("could not look up account SID: error code %lu", + GetLastError()); } free(tokenuser); @@ -870,8 +997,7 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) superuser_name = get_user_name(&errstr); if (superuser_name == NULL) { - fprintf(stderr, "%s: %s\n", progname, errstr); - exit(2); + bail("%s", errstr); } } @@ -902,9 +1028,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) do { \ if (!(cond)) \ { \ - fprintf(stderr, _("%s: could not write to file \"%s\": %s\n"), \ - progname, fname, strerror(errno)); \ - exit(2); \ + bail("could not write to file \"%s\": %s", \ + fname, strerror(errno)); \ } \ } while (0) @@ -915,15 +1040,13 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) * Truncating this name is a fatal error, because we must not fail to * overwrite an original trust-authentication pg_hba.conf. */ - fprintf(stderr, _("%s: directory name too long\n"), progname); - exit(2); + bail("directory name too long"); } hba = fopen(fname, "w"); if (hba == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", hba) >= 0); CW(fputs("host all all 127.0.0.1/32 sspi include_realm=1 map=regress\n", @@ -937,9 +1060,8 @@ config_sspi_auth(const char *pgdata, const char *superuser_name) ident = fopen(fname, "w"); if (ident == NULL) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, fname, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + fname, strerror(errno)); } CW(fputs("# Configuration written by config_sspi_auth()\n", ident) >= 0); @@ -973,7 +1095,7 @@ psql_start_command(void) StringInfo buf = makeStringInfo(); appendStringInfo(buf, - "\"%s%spsql\" -X", + "\"%s%spsql\" -X -q", bindir ? bindir : "", bindir ? "/" : ""); return buf; @@ -1029,8 +1151,7 @@ psql_end_command(StringInfo buf, const char *database) if (system(buf->data) != 0) { /* psql probably already reported the error */ - fprintf(stderr, _("command failed: %s\n"), buf->data); - exit(2); + bail("command failed: %s", buf->data); } /* Clean up */ @@ -1071,9 +1192,7 @@ spawn_process(const char *cmdline) pid = fork(); if (pid == -1) { - fprintf(stderr, _("%s: could not fork: %s\n"), - progname, strerror(errno)); - exit(2); + bail("could not fork: %s", strerror(errno)); } if (pid == 0) { @@ -1088,9 +1207,8 @@ spawn_process(const char *cmdline) cmdline2 = psprintf("exec %s", cmdline); execl(shellprog, shellprog, "-c", cmdline2, (char *) NULL); - fprintf(stderr, _("%s: could not exec \"%s\": %s\n"), - progname, shellprog, strerror(errno)); - _exit(1); /* not exit() here... */ + /* Not using the normal bail() here as we want _exit */ + bail_noatexit("could not exec \"%s\": %s", shellprog, strerror(errno)); } /* in parent */ return pid; @@ -1128,8 +1246,8 @@ file_size(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } fseek(f, 0, SEEK_END); @@ -1150,8 +1268,8 @@ file_line_count(const char *file) if (!f) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, file, strerror(errno)); + diag("could not open file \"%s\" for reading: %s", + file, strerror(errno)); return -1; } while ((c = fgetc(f)) != EOF) @@ -1192,9 +1310,7 @@ make_directory(const char *dir) { if (mkdir(dir, S_IRWXU | S_IRWXG | S_IRWXO) < 0) { - fprintf(stderr, _("%s: could not create directory \"%s\": %s\n"), - progname, dir, strerror(errno)); - exit(2); + bail("could not create directory \"%s\": %s", dir, strerror(errno)); } } @@ -1244,8 +1360,7 @@ run_diff(const char *cmd, const char *filename) r = system(cmd); if (!WIFEXITED(r) || WEXITSTATUS(r) > 1) { - fprintf(stderr, _("diff command failed with status %d: %s\n"), r, cmd); - exit(2); + bail("diff command failed with status %d: %s", r, cmd); } #ifdef WIN32 @@ -1255,8 +1370,7 @@ run_diff(const char *cmd, const char *filename) */ if (WEXITSTATUS(r) == 1 && file_size(filename) <= 0) { - fprintf(stderr, _("diff command not found: %s\n"), cmd); - exit(2); + bail("diff command not found: %s", cmd); } #endif @@ -1327,9 +1441,8 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul alt_expectfile = get_alternative_expectfile(expectfile, i); if (!alt_expectfile) { - fprintf(stderr, _("Unable to check secondary comparison files: %s\n"), - strerror(errno)); - exit(2); + bail("Unable to check secondary comparison files: %s", + strerror(errno)); } if (!file_exists(alt_expectfile)) @@ -1444,9 +1557,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, if (p == INVALID_PID) { - fprintf(stderr, _("failed to wait for subprocesses: %s\n"), - strerror(errno)); - exit(2); + bail("failed to wait for subprocesses: %s", strerror(errno)); } #else DWORD exit_status; @@ -1455,9 +1566,8 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, r = WaitForMultipleObjects(tests_left, active_pids, FALSE, INFINITE); if (r < WAIT_OBJECT_0 || r >= WAIT_OBJECT_0 + tests_left) { - fprintf(stderr, _("failed to wait for subprocesses: error code %lu\n"), - GetLastError()); - exit(2); + bail("failed to wait for subprocesses: error code %lu", + GetLastError()); } p = active_pids[r - WAIT_OBJECT_0]; /* compact the active_pids array */ @@ -1476,7 +1586,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes, statuses[i] = (int) exit_status; INSTR_TIME_SET_CURRENT(stoptimes[i]); if (names) - status(" %s", names[i]); + note_detail(" %s", names[i]); tests_left--; break; } @@ -1495,21 +1605,20 @@ static void log_child_failure(int exitstatus) { if (WIFEXITED(exitstatus)) - status(_(" (test process exited with exit code %d)"), - WEXITSTATUS(exitstatus)); + diag("(test process exited with exit code %d)", + WEXITSTATUS(exitstatus)); else if (WIFSIGNALED(exitstatus)) { #if defined(WIN32) - status(_(" (test process was terminated by exception 0x%X)"), - WTERMSIG(exitstatus)); + diag("(test process was terminated by exception 0x%X)", + WTERMSIG(exitstatus)); #else - status(_(" (test process was terminated by signal %d: %s)"), - WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); + diag("(test process was terminated by signal %d: %s)", + WTERMSIG(exitstatus), pg_strsignal(WTERMSIG(exitstatus))); #endif } else - status(_(" (test process exited with unrecognized status %d)"), - exitstatus); + diag("(test process exited with unrecognized status %d)", exitstatus); } /* @@ -1540,9 +1649,8 @@ run_schedule(const char *schedule, test_start_function startfunc, scf = fopen(schedule, "r"); if (!scf) { - fprintf(stderr, _("%s: could not open file \"%s\" for reading: %s\n"), - progname, schedule, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for reading: %s", + schedule, strerror(errno)); } while (fgets(scbuf, sizeof(scbuf), scf)) @@ -1566,9 +1674,8 @@ run_schedule(const char *schedule, test_start_function startfunc, test = scbuf + 6; else { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } num_tests = 0; @@ -1584,9 +1691,8 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests >= MAX_PARALLEL_TESTS) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - MAX_PARALLEL_TESTS, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + MAX_PARALLEL_TESTS, schedule, line_num, scbuf); } sav = *c; *c = '\0'; @@ -1608,14 +1714,12 @@ run_schedule(const char *schedule, test_start_function startfunc, if (num_tests == 0) { - fprintf(stderr, _("syntax error in schedule file \"%s\" line %d: %s\n"), - schedule, line_num, scbuf); - exit(2); + bail("syntax error in schedule file \"%s\" line %d: %s", + schedule, line_num, scbuf); } if (num_tests == 1) { - status(_("test %-28s ... "), tests[0]); pids[0] = (startfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]); INSTR_TIME_SET_CURRENT(starttimes[0]); wait_for_tests(pids, statuses, stoptimes, NULL, 1); @@ -1623,16 +1727,15 @@ run_schedule(const char *schedule, test_start_function startfunc, } else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests) { - fprintf(stderr, _("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s\n"), - max_concurrent_tests, schedule, line_num, scbuf); - exit(2); + bail("too many parallel tests (more than %d) in schedule file \"%s\" line %d: %s", + max_concurrent_tests, schedule, line_num, scbuf); } else if (max_connections > 0 && max_connections < num_tests) { int oldest = 0; - status(_("parallel group (%d tests, in groups of %d): "), - num_tests, max_connections); + note_detail("parallel group (%d tests, in groups of %d): ", + num_tests, max_connections); for (i = 0; i < num_tests; i++) { if (i - oldest >= max_connections) @@ -1648,18 +1751,18 @@ run_schedule(const char *schedule, test_start_function startfunc, wait_for_tests(pids + oldest, statuses + oldest, stoptimes + oldest, tests + oldest, i - oldest); - status_end(); + note_end(); } else { - status(_("parallel group (%d tests): "), num_tests); + note_detail("parallel group (%d tests): ", num_tests); for (i = 0; i < num_tests; i++) { pids[i] = (startfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]); INSTR_TIME_SET_CURRENT(starttimes[i]); } wait_for_tests(pids, statuses, stoptimes, tests, num_tests); - status_end(); + note_end(); } /* Check results for all tests */ @@ -1670,8 +1773,7 @@ run_schedule(const char *schedule, test_start_function startfunc, *tl; bool differ = false; - if (num_tests > 1) - status(_(" %-28s ... "), tests[i]); + INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); /* * Advance over all three lists simultaneously. @@ -1692,36 +1794,27 @@ run_schedule(const char *schedule, test_start_function startfunc, newdiff = results_differ(tests[i], rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } if (statuses[i] != 0) { - status(_("FAILED")); + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); log_child_failure(statuses[i]); - fail_count++; } else { - if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1)); } } - - INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i])); - - status_end(); } for (i = 0; i < num_tests; i++) @@ -1756,7 +1849,6 @@ run_single_test(const char *test, test_start_function startfunc, *tl; bool differ = false; - status(_("test %-28s ... "), test); pid = (startfunc) (test, &resultfiles, &expectfiles, &tags); INSTR_TIME_SET_CURRENT(starttime); wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1); @@ -1780,35 +1872,29 @@ run_single_test(const char *test, test_start_function startfunc, newdiff = results_differ(test, rl->str, el->str); if (newdiff && tl) { - printf("%s ", tl->str); + diag("tag: %s", tl->str); } differ |= newdiff; } + INSTR_TIME_SUBTRACT(stoptime, starttime); + if (exit_status != 0) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); log_child_failure(exit_status); } else { if (differ) { - status(_("FAILED")); - fail_count++; + test_status_failed(test, false, INSTR_TIME_GET_MILLISEC(stoptime)); } else { - status(_("ok ")); /* align with FAILED */ - success_count++; + test_status_ok(test, INSTR_TIME_GET_MILLISEC(stoptime), false); } } - - INSTR_TIME_SUBTRACT(stoptime, starttime); - status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptime)); - - status_end(); } /* @@ -1830,9 +1916,8 @@ open_result_files(void) logfile = fopen(logfilename, "w"); if (!logfile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, logfilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + logfilename, strerror(errno)); } /* create the diffs file as empty */ @@ -1841,9 +1926,8 @@ open_result_files(void) difffile = fopen(difffilename, "w"); if (!difffile) { - fprintf(stderr, _("%s: could not open file \"%s\" for writing: %s\n"), - progname, difffilename, strerror(errno)); - exit(2); + bail("could not open file \"%s\" for writing: %s", + difffilename, strerror(errno)); } /* we don't keep the diffs file open continuously */ fclose(difffile); @@ -1859,7 +1943,6 @@ drop_database_if_exists(const char *dbname) { StringInfo buf = psql_start_command(); - header(_("dropping database \"%s\""), dbname); /* Set warning level so we don't see chatter about nonexistent DB */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP DATABASE IF EXISTS \"%s\"", dbname); @@ -1876,7 +1959,6 @@ create_database(const char *dbname) * We use template0 so that any installation-local cruft in template1 will * not mess up the tests. */ - header(_("creating database \"%s\""), dbname); if (encoding) psql_add_command(buf, "CREATE DATABASE \"%s\" TEMPLATE=template0 ENCODING='%s'%s", dbname, encoding, (nolocale) ? " LC_COLLATE='C' LC_CTYPE='C'" : ""); @@ -1898,10 +1980,7 @@ create_database(const char *dbname) * this will work whether or not the extension is preinstalled. */ for (sl = loadextension; sl != NULL; sl = sl->next) - { - header(_("installing %s"), sl->str); psql_command(dbname, "CREATE EXTENSION IF NOT EXISTS \"%s\"", sl->str); - } } static void @@ -1909,7 +1988,6 @@ drop_role_if_exists(const char *rolename) { StringInfo buf = psql_start_command(); - header(_("dropping role \"%s\""), rolename); /* Set warning level so we don't see chatter about nonexistent role */ psql_add_command(buf, "SET client_min_messages = warning"); psql_add_command(buf, "DROP ROLE IF EXISTS \"%s\"", rolename); @@ -1921,7 +1999,6 @@ create_role(const char *rolename, const _stringlist *granted_dbs) { StringInfo buf = psql_start_command(); - header(_("creating role \"%s\""), rolename); psql_add_command(buf, "CREATE ROLE \"%s\" WITH LOGIN", rolename); for (; granted_dbs != NULL; granted_dbs = granted_dbs->next) { @@ -2143,8 +2220,8 @@ regression_main(int argc, char *argv[], break; default: /* getopt_long already emitted a complaint */ - fprintf(stderr, _("\nTry \"%s -h\" for more information.\n"), - progname); + pg_log_error_hint("Try \"%s --help\" for more information.", + progname); exit(2); } } @@ -2164,9 +2241,7 @@ regression_main(int argc, char *argv[], */ if (!(dblist && dblist->str && dblist->str[0])) { - fprintf(stderr, _("%s: no database name was specified\n"), - progname); - exit(2); + bail("no database name was specified"); } if (config_auth_datadir) @@ -2217,17 +2292,12 @@ regression_main(int argc, char *argv[], if (directory_exists(temp_instance)) { - header(_("removing existing temp instance")); if (!rmtree(temp_instance, true)) { - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); - exit(2); + bail("could not remove temp instance \"%s\"", temp_instance); } } - header(_("creating temporary instance")); - /* make the temp instance top directory */ make_directory(temp_instance); @@ -2237,7 +2307,6 @@ regression_main(int argc, char *argv[], make_directory(buf); /* initdb */ - header(_("initializing database system")); snprintf(buf, sizeof(buf), "\"%s%sinitdb\" -D \"%s/data\" --no-clean --no-sync%s%s > \"%s/log/initdb.log\" 2>&1", bindir ? bindir : "", @@ -2249,8 +2318,10 @@ regression_main(int argc, char *argv[], fflush(NULL); if (system(buf)) { - fprintf(stderr, _("\n%s: initdb failed\nExamine %s/log/initdb.log for the reason.\nCommand was: %s\n"), progname, outputdir, buf); - exit(2); + bail("initdb failed\n" + "# Examine \"%s/log/initdb.log\" for the reason.\n" + "# Command was: %s", + outputdir, buf); } /* @@ -2265,8 +2336,8 @@ regression_main(int argc, char *argv[], pg_conf = fopen(buf, "a"); if (pg_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" for adding extra config: %s\n"), progname, buf, strerror(errno)); - exit(2); + bail("could not open \"%s\" for adding extra config: %s", + buf, strerror(errno)); } fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); @@ -2285,8 +2356,8 @@ regression_main(int argc, char *argv[], extra_conf = fopen(temp_config, "r"); if (extra_conf == NULL) { - fprintf(stderr, _("\n%s: could not open \"%s\" to read extra config: %s\n"), progname, temp_config, strerror(errno)); - exit(2); + bail("could not open \"%s\" to read extra config: %s", + temp_config, strerror(errno)); } while (fgets(line_buf, sizeof(line_buf), extra_conf) != NULL) fputs(line_buf, pg_conf); @@ -2325,14 +2396,13 @@ regression_main(int argc, char *argv[], if (port_specified_by_user || i == 15) { - fprintf(stderr, _("port %d apparently in use\n"), port); + note("port %d apparently in use", port); if (!port_specified_by_user) - fprintf(stderr, _("%s: could not determine an available port\n"), progname); - fprintf(stderr, _("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers.\n")); - exit(2); + note("could not determine an available port"); + bail("Specify an unused port using the --port option or shut down any conflicting PostgreSQL servers."); } - fprintf(stderr, _("port %d apparently in use, trying %d\n"), port, port + 1); + note("port %d apparently in use, trying %d", port, port + 1); port++; sprintf(s, "%d", port); setenv("PGPORT", s, 1); @@ -2344,7 +2414,6 @@ regression_main(int argc, char *argv[], /* * Start the temp postmaster */ - header(_("starting postmaster")); snprintf(buf, sizeof(buf), "\"%s%spostgres\" -D \"%s/data\" -F%s " "-c \"listen_addresses=%s\" -k \"%s\" " @@ -2356,11 +2425,7 @@ regression_main(int argc, char *argv[], outputdir); postmaster_pid = spawn_process(buf); if (postmaster_pid == INVALID_PID) - { - fprintf(stderr, _("\n%s: could not spawn postmaster: %s\n"), - progname, strerror(errno)); - exit(2); - } + bail("could not spawn postmaster: %s", strerror(errno)); /* * Wait till postmaster is able to accept connections; normally this @@ -2395,16 +2460,16 @@ regression_main(int argc, char *argv[], if (WaitForSingleObject(postmaster_pid, 0) == WAIT_OBJECT_0) #endif { - fprintf(stderr, _("\n%s: postmaster failed\nExamine %s/log/postmaster.log for the reason\n"), progname, outputdir); - exit(2); + bail("postmaster failed, examine \"%s/log/postmaster.log\" for the reason", + outputdir); } pg_usleep(1000000L); } if (i >= wait_seconds) { - fprintf(stderr, _("\n%s: postmaster did not respond within %d seconds\nExamine %s/log/postmaster.log for the reason\n"), - progname, wait_seconds, outputdir); + diag("postmaster did not respond within %d seconds, examine \"%s/log/postmaster.log\" for the reason", + wait_seconds, outputdir); /* * If we get here, the postmaster is probably wedged somewhere in @@ -2413,17 +2478,14 @@ regression_main(int argc, char *argv[], * attempts. */ #ifndef WIN32 - if (kill(postmaster_pid, SIGKILL) != 0 && - errno != ESRCH) - fprintf(stderr, _("\n%s: could not kill failed postmaster: %s\n"), - progname, strerror(errno)); + if (kill(postmaster_pid, SIGKILL) != 0 && errno != ESRCH) + bail("could not kill failed postmaster: %s", strerror(errno)); #else if (TerminateProcess(postmaster_pid, 255) == 0) - fprintf(stderr, _("\n%s: could not kill failed postmaster: error code %lu\n"), - progname, GetLastError()); + bail("could not kill failed postmaster: error code %lu", + GetLastError()); #endif - - exit(2); + bail("postmaster failed"); } postmaster_running = true; @@ -2434,8 +2496,8 @@ regression_main(int argc, char *argv[], #else #define ULONGPID(x) (unsigned long) (x) #endif - printf(_("running on port %d with PID %lu\n"), - port, ULONGPID(postmaster_pid)); + note("using temp instance on port %d with PID %lu", + port, ULONGPID(postmaster_pid)); } else { @@ -2466,8 +2528,6 @@ regression_main(int argc, char *argv[], /* * Ready to run the tests */ - header(_("running regression test queries")); - for (sl = schedulelist; sl != NULL; sl = sl->next) { run_schedule(sl->str, startfunc, postfunc); @@ -2483,7 +2543,6 @@ regression_main(int argc, char *argv[], */ if (temp_instance) { - header(_("shutting down postmaster")); stop_postmaster(); } @@ -2494,42 +2553,30 @@ regression_main(int argc, char *argv[], */ if (temp_instance && fail_count == 0) { - header(_("removing temporary instance")); if (!rmtree(temp_instance, true)) - fprintf(stderr, _("\n%s: could not remove temp instance \"%s\"\n"), - progname, temp_instance); + diag("could not remove temp instance \"%s\"", + temp_instance); } - fclose(logfile); + /* + * Emit a TAP compliant Plan + */ + plan(fail_count + success_count); /* * Emit nice-looking summary message */ if (fail_count == 0) - snprintf(buf, sizeof(buf), - _(" All %d tests passed. "), - success_count); + note("All %d tests passed.", success_count); else - snprintf(buf, sizeof(buf), - _(" %d of %d tests failed. "), - fail_count, - success_count + fail_count); - - putchar('\n'); - for (i = strlen(buf); i > 0; i--) - putchar('='); - printf("\n%s\n", buf); - for (i = strlen(buf); i > 0; i--) - putchar('='); - putchar('\n'); - putchar('\n'); + diag("%d of %d tests failed.", fail_count, success_count + fail_count); if (file_size(difffilename) > 0) { - printf(_("The differences that caused some tests to fail can be viewed in the\n" - "file \"%s\". A copy of the test summary that you see\n" - "above is saved in the file \"%s\".\n\n"), - difffilename, logfilename); + diag("The differences that caused some tests to fail can be viewed in the file \"%s\".", + difffilename); + diag("A copy of the test summary that you see above is saved in the file \"%s\".", + logfilename); } else { @@ -2537,6 +2584,9 @@ regression_main(int argc, char *argv[], unlink(logfilename); } + fclose(logfile); + logfile = NULL; + if (fail_count != 0) exit(1); -- 2.32.1 (Apple Git-133) ^ permalink raw reply [nested|flat] 14+ messages in thread
* Re: TAP output format in pg_regress @ 2023-03-31 11:12 Daniel Gustafsson <[email protected]> parent: Daniel Gustafsson <[email protected]> 0 siblings, 0 replies; 14+ messages in thread From: Daniel Gustafsson @ 2023-03-31 11:12 UTC (permalink / raw) To: Peter Eisentraut <[email protected]>; +Cc: vignesh C <[email protected]>; Nikolay Shaplov <[email protected]>; Andres Freund <[email protected]>; Dagfinn Ilmari Mannsåker <[email protected]>; PostgreSQL Developers <[email protected]>; Andrew Dunstan <[email protected]>; Tom Lane <[email protected]> > On 29 Mar 2023, at 22:08, Daniel Gustafsson <[email protected]> wrote: > >> On 29 Mar 2023, at 21:14, Daniel Gustafsson <[email protected]> wrote: > >> Ugh, I clearly should've stayed on the couch yesterday. > > Maybe today as well, just as I had sent this I realized there is mention of the > output format in the docs that I had missed. The attached changes that as well > to match the new format. (The section in question doesn't mention using meson, > but I have a feeling that's tackled in one of the meson docs threads.) Pushed to master now with a few tweaks to comments and docs. Thanks for all the reviews, I hope the new format will make meson builds easier/better without compromising the human readable aspect of traditional builds. -- Daniel Gustafsson ^ permalink raw reply [nested|flat] 14+ messages in thread
end of thread, other threads:[~2023-03-31 11:12 UTC | newest] Thread overview: 14+ messages (download: mbox mbox.gz follow: Atom feed) -- links below jump to the message on this page -- 2021-02-03 12:00 [PATCH 1/1] Fix a corner-case in COPY FROM backslash processing. Heikki Linnakangas <[email protected]> 2023-01-03 10:31 Re: TAP output format in pg_regress vignesh C <[email protected]> 2023-01-06 05:50 ` Re: TAP output format in pg_regress vignesh C <[email protected]> 2023-01-19 11:14 ` Re: TAP output format in pg_regress vignesh C <[email protected]> 2023-01-23 11:42 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-01-23 11:43 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-02-24 09:49 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-03-15 10:36 ` Re: TAP output format in pg_regress Peter Eisentraut <[email protected]> 2023-03-28 13:26 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-03-28 13:56 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-03-29 07:08 ` Re: TAP output format in pg_regress Peter Eisentraut <[email protected]> 2023-03-29 19:14 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-03-29 20:08 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]> 2023-03-31 11:12 ` Re: TAP output format in pg_regress Daniel Gustafsson <[email protected]>
This inbox is served by agora; see mirroring instructions for how to clone and mirror all data and code used for this inbox