Обсуждение: Reporting script runtimes in pg_regress

Поиск
Список
Период
Сортировка

Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
I've wondered for some time whether we couldn't make a useful
reduction in the run time of the PG regression tests by looking
for scripts that run significantly longer than others in their
parallel groups, and making an effort to trim the runtimes of
those particular scripts.

The first step in that of course is to get some data, so attached
is a patch to pg_regress to cause it to print the runtime of each
script.  This produces results like, say,

parallel group (17 tests):  circle line timetz path lseg point macaddr macaddr8 time interval inet tstypes date box
timestamptimestamptz polygon 
     point                        ... ok (35 ms)
     lseg                         ... ok (31 ms)
     line                         ... ok (23 ms)
     box                          ... ok (135 ms)
     path                         ... ok (24 ms)
     polygon                      ... ok (1256 ms)
     circle                       ... ok (20 ms)
     date                         ... ok (69 ms)
     time                         ... ok (40 ms)
     timetz                       ... ok (22 ms)
     timestamp                    ... ok (378 ms)
     timestamptz                  ... ok (378 ms)
     interval                     ... ok (50 ms)
     inet                         ... ok (56 ms)
     macaddr                      ... ok (33 ms)
     macaddr8                     ... ok (37 ms)
     tstypes                      ... ok (62 ms)

or on a rather slower machine,

parallel group (8 tests):  hash_part reloptions partition_info identity partition_join partition_aggregate
partition_pruneindexing 
     identity                     ... ok (3807 ms)
     partition_join               ... ok (10433 ms)
     partition_prune              ... ok (19370 ms)
     reloptions                   ... ok (1166 ms)
     hash_part                    ... ok (628 ms)
     indexing                     ... ok (22070 ms)
     partition_aggregate          ... ok (12731 ms)
     partition_info               ... ok (1373 ms)
test event_trigger                ... ok (1953 ms)
test fast_default                 ... ok (2689 ms)
test stats                        ... ok (1173 ms)

Does anyone else feel that this is interesting/useful data?

            regards, tom lane

diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
index 4b742a1..a4caa22 100644
--- a/src/test/regress/pg_regress.c
+++ b/src/test/regress/pg_regress.c
@@ -36,6 +36,7 @@
 #include "getopt_long.h"
 #include "libpq/pqcomm.h"        /* needed for UNIXSOCK_PATH() */
 #include "pg_config_paths.h"
+#include "portability/instr_time.h"

 /* for resultmap we need a list of pairs of strings */
 typedef struct _resultmap
@@ -1473,14 +1474,15 @@ results_differ(const char *testname, const char *resultsfile, const char *defaul

 /*
  * Wait for specified subprocesses to finish, and return their exit
- * statuses into statuses[]
+ * statuses into statuses[] and stop times into stoptimes[]
  *
  * If names isn't NULL, print each subprocess's name as it finishes
  *
  * Note: it's OK to scribble on the pids array, but not on the names array
  */
 static void
-wait_for_tests(PID_TYPE * pids, int *statuses, char **names, int num_tests)
+wait_for_tests(PID_TYPE * pids, int *statuses, instr_time *stoptimes,
+               char **names, int num_tests)
 {
     int            tests_left;
     int            i;
@@ -1533,6 +1535,7 @@ wait_for_tests(PID_TYPE * pids, int *statuses, char **names, int num_tests)
 #endif
                 pids[i] = INVALID_PID;
                 statuses[i] = (int) exit_status;
+                INSTR_TIME_SET_CURRENT(stoptimes[i]);
                 if (names)
                     status(" %s", names[i]);
                 tests_left--;
@@ -1582,6 +1585,8 @@ run_schedule(const char *schedule, test_function tfunc)
     _stringlist *expectfiles[MAX_PARALLEL_TESTS];
     _stringlist *tags[MAX_PARALLEL_TESTS];
     PID_TYPE    pids[MAX_PARALLEL_TESTS];
+    instr_time    starttimes[MAX_PARALLEL_TESTS];
+    instr_time    stoptimes[MAX_PARALLEL_TESTS];
     int            statuses[MAX_PARALLEL_TESTS];
     _stringlist *ignorelist = NULL;
     char        scbuf[1024];
@@ -1687,7 +1692,8 @@ run_schedule(const char *schedule, test_function tfunc)
         {
             status(_("test %-28s ... "), tests[0]);
             pids[0] = (tfunc) (tests[0], &resultfiles[0], &expectfiles[0], &tags[0]);
-            wait_for_tests(pids, statuses, NULL, 1);
+            INSTR_TIME_SET_CURRENT(starttimes[0]);
+            wait_for_tests(pids, statuses, stoptimes, NULL, 1);
             /* status line is finished below */
         }
         else if (max_concurrent_tests > 0 && max_concurrent_tests < num_tests)
@@ -1707,12 +1713,15 @@ run_schedule(const char *schedule, test_function tfunc)
                 if (i - oldest >= max_connections)
                 {
                     wait_for_tests(pids + oldest, statuses + oldest,
+                                   stoptimes + oldest,
                                    tests + oldest, i - oldest);
                     oldest = i;
                 }
                 pids[i] = (tfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]);
+                INSTR_TIME_SET_CURRENT(starttimes[i]);
             }
             wait_for_tests(pids + oldest, statuses + oldest,
+                           stoptimes + oldest,
                            tests + oldest, i - oldest);
             status_end();
         }
@@ -1722,8 +1731,9 @@ run_schedule(const char *schedule, test_function tfunc)
             for (i = 0; i < num_tests; i++)
             {
                 pids[i] = (tfunc) (tests[i], &resultfiles[i], &expectfiles[i], &tags[i]);
+                INSTR_TIME_SET_CURRENT(starttimes[i]);
             }
-            wait_for_tests(pids, statuses, tests, num_tests);
+            wait_for_tests(pids, statuses, stoptimes, tests, num_tests);
             status_end();
         }

@@ -1793,6 +1803,9 @@ run_schedule(const char *schedule, test_function tfunc)
             if (statuses[i] != 0)
                 log_child_failure(statuses[i]);

+            INSTR_TIME_SUBTRACT(stoptimes[i], starttimes[i]);
+            status(_(" (%.0f ms)"), INSTR_TIME_GET_MILLISEC(stoptimes[i]));
+
             status_end();
         }

@@ -1818,6 +1831,8 @@ static void
 run_single_test(const char *test, test_function tfunc)
 {
     PID_TYPE    pid;
+    instr_time    starttime;
+    instr_time    stoptime;
     int            exit_status;
     _stringlist *resultfiles = NULL;
     _stringlist *expectfiles = NULL;
@@ -1829,7 +1844,8 @@ run_single_test(const char *test, test_function tfunc)

     status(_("test %-28s ... "), test);
     pid = (tfunc) (test, &resultfiles, &expectfiles, &tags);
-    wait_for_tests(&pid, &exit_status, NULL, 1);
+    INSTR_TIME_SET_CURRENT(starttime);
+    wait_for_tests(&pid, &exit_status, &stoptime, NULL, 1);

     /*
      * Advance over all three lists simultaneously.
@@ -1867,6 +1883,9 @@ run_single_test(const char *test, test_function tfunc)
     if (exit_status != 0)
         log_child_failure(exit_status);

+    INSTR_TIME_SUBTRACT(stoptime, starttime);
+    status(_(" (%.0f ms)"), INSTR_TIME_GET_MILLISEC(stoptime));
+
     status_end();
 }


Re: Reporting script runtimes in pg_regress

От
Peter Geoghegan
Дата:
On Sat, Feb 9, 2019 at 7:50 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I've wondered for some time whether we couldn't make a useful
> reduction in the run time of the PG regression tests by looking
> for scripts that run significantly longer than others in their
> parallel groups, and making an effort to trim the runtimes of
> those particular scripts.

> Does anyone else feel that this is interesting/useful data?

It definitely seems useful to me.

-- 
Peter Geoghegan


Re: Reporting script runtimes in pg_regress

От
Andres Freund
Дата:
Hi,

On February 10, 2019 9:20:18 AM GMT+05:30, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>I've wondered for some time whether we couldn't make a useful
>reduction in the run time of the PG regression tests by looking
>for scripts that run significantly longer than others in their
>parallel groups, and making an effort to trim the runtimes of
>those particular scripts.
>
>The first step in that of course is to get some data, so attached
>is a patch to pg_regress to cause it to print the runtime of each
>script.  This produces results like, say,
>
>parallel group (17 tests):  circle line timetz path lseg point macaddr
>macaddr8 time interval inet tstypes date box timestamp timestamptz
>polygon
>     point                        ... ok (35 ms)
>     lseg                         ... ok (31 ms)
>     line                         ... ok (23 ms)
>     box                          ... ok (135 ms)
>     path                         ... ok (24 ms)
>     polygon                      ... ok (1256 ms)
>     circle                       ... ok (20 ms)
>     date                         ... ok (69 ms)
>     time                         ... ok (40 ms)
>     timetz                       ... ok (22 ms)
>     timestamp                    ... ok (378 ms)
>     timestamptz                  ... ok (378 ms)
>     interval                     ... ok (50 ms)
>     inet                         ... ok (56 ms)
>     macaddr                      ... ok (33 ms)
>     macaddr8                     ... ok (37 ms)
>     tstypes                      ... ok (62 ms)
>
>or on a rather slower machine,
>
>parallel group (8 tests):  hash_part reloptions partition_info identity
>partition_join partition_aggregate partition_prune indexing
>     identity                     ... ok (3807 ms)
>     partition_join               ... ok (10433 ms)
>     partition_prune              ... ok (19370 ms)
>     reloptions                   ... ok (1166 ms)
>     hash_part                    ... ok (628 ms)
>     indexing                     ... ok (22070 ms)
>     partition_aggregate          ... ok (12731 ms)
>     partition_info               ... ok (1373 ms)
>test event_trigger                ... ok (1953 ms)
>test fast_default                 ... ok (2689 ms)
>test stats                        ... ok (1173 ms)
>
>Does anyone else feel that this is interesting/useful data?

Yes, it does. I've locally been playing with parallelizing isolationtester's schedule, and it's quite useful for coming
upwith a schedule that's optimized. 

Andres
--
Sent from my Android device with K-9 Mail. Please excuse my brevity.


Re: Reporting script runtimes in pg_regress

От
Daniel Gustafsson
Дата:
> On 10 Feb 2019, at 04:50, Tom Lane <tgl@sss.pgh.pa.us> wrote:

> Does anyone else feel that this is interesting/useful data?

Absolutely, +1 on this.  In Greenplum we print the runtime of the script and
the runtime of the diff, both of which have provided useful feedback on where
to best spend optimization efforts (the diff time of course being a lot less
interesting in upstream postgres due to gpdb having it’s own diff tool to
handle segment variability).

cheers ./daniel

Re: Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
Daniel Gustafsson <daniel@yesql.se> writes:
>> On 10 Feb 2019, at 04:50, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Does anyone else feel that this is interesting/useful data?

> Absolutely, +1 on this.  In Greenplum we print the runtime of the script and
> the runtime of the diff, both of which have provided useful feedback on where
> to best spend optimization efforts (the diff time of course being a lot less
> interesting in upstream postgres due to gpdb having it’s own diff tool to
> handle segment variability).

Seems like I'm far from the first to think of this --- I wonder why
nobody submitted a patch before?

Anyway, pushed.

            regards, tom lane


Re: Reporting script runtimes in pg_regress

От
Peter Eisentraut
Дата:
On 10/02/2019 22:55, Tom Lane wrote:
> Daniel Gustafsson <daniel@yesql.se> writes:
>>> On 10 Feb 2019, at 04:50, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>> Does anyone else feel that this is interesting/useful data?
> 
>> Absolutely, +1 on this.  In Greenplum we print the runtime of the script and
>> the runtime of the diff, both of which have provided useful feedback on where
>> to best spend optimization efforts (the diff time of course being a lot less
>> interesting in upstream postgres due to gpdb having it’s own diff tool to
>> handle segment variability).
> 
> Seems like I'm far from the first to think of this --- I wonder why
> nobody submitted a patch before?

Now that I see this in action, it makes the actual test results harder
to identify flying by.  I understand the desire to collect this timing
data, but that is a special use case and not relevant to the normal use
of the test suite, which is to see whether the test passes.  Can we make
this optional please?

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> Now that I see this in action, it makes the actual test results harder
> to identify flying by.  I understand the desire to collect this timing
> data, but that is a special use case and not relevant to the normal use
> of the test suite, which is to see whether the test passes.  Can we make
> this optional please?

Well, I want the buildfarm to produce this info, so it's hard to see
how to get that without the timings being included by default.  I take
your point that it makes the display look a bit cluttered, though.
Would it help to put more whitespace between the status and the timing?

            regards, tom lane


Re: Reporting script runtimes in pg_regress

От
Amit Langote
Дата:
On 2019/02/11 23:30, Tom Lane wrote:
> Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
>> Now that I see this in action, it makes the actual test results harder
>> to identify flying by.  I understand the desire to collect this timing
>> data, but that is a special use case and not relevant to the normal use
>> of the test suite, which is to see whether the test passes.  Can we make
>> this optional please?
> 
> Well, I want the buildfarm to produce this info, so it's hard to see
> how to get that without the timings being included by default.  I take
> your point that it makes the display look a bit cluttered, though.
> Would it help to put more whitespace between the status and the timing?

+1.  Maybe, not as much whitespace as we get today between the test name
and "... ok", but at least more than just a single space.

Thanks,
Amit



Re: Reporting script runtimes in pg_regress

От
Michael Paquier
Дата:
On Tue, Feb 12, 2019 at 10:29:40AM +0900, Amit Langote wrote:
> On 2019/02/11 23:30, Tom Lane wrote:
>> Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
>>> Now that I see this in action, it makes the actual test results harder
>>> to identify flying by.  I understand the desire to collect this timing
>>> data, but that is a special use case and not relevant to the normal use
>>> of the test suite, which is to see whether the test passes.  Can we make
>>> this optional please?
>>
>> Well, I want the buildfarm to produce this info, so it's hard to see
>> how to get that without the timings being included by default.  I take
>> your point that it makes the display look a bit cluttered, though.
>> Would it help to put more whitespace between the status and the timing?
>
> +1.  Maybe, not as much whitespace as we get today between the test name
> and "... ok", but at least more than just a single space.

Sure, but do we need feedback immediately?  I am just catching up on
that, and I too find a bit annoying that this is not controlled by a
switch which is disabled by default.  It seems to me that this points
out to another issue that there is no actual way to pass down custom
options to pg_regress other than PG_REGRESS_DIFF_OPTS to control the
diff output format.  So we may also want something like
PG_REGRESS_OPTS.
--
Michael

Вложения

Re: Reporting script runtimes in pg_regress

От
Peter Eisentraut
Дата:
On 2019-02-11 15:30, Tom Lane wrote:
> Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
>> Now that I see this in action, it makes the actual test results harder
>> to identify flying by.  I understand the desire to collect this timing
>> data, but that is a special use case and not relevant to the normal use
>> of the test suite, which is to see whether the test passes.  Can we make
>> this optional please?
> 
> Well, I want the buildfarm to produce this info, so it's hard to see
> how to get that without the timings being included by default.  I take
> your point that it makes the display look a bit cluttered, though.

Can we enable it through the buildfarm client?

Or we could write it into a separate log file.

> Would it help to put more whitespace between the status and the timing?

prove --timer produces this:

[14:21:32] t/001_basic.pl ............ ok     9154 ms ( 0.00 usr  0.01 sys +  2.28 cusr  3.40 csys =  5.69 CPU)
[14:21:41] t/002_databases.pl ........ ok    11294 ms ( 0.00 usr  0.00 sys +  2.16 cusr  3.84 csys =  6.00 CPU)
[14:21:52] t/003_extrafiles.pl ....... ok     7736 ms ( 0.00 usr  0.00 sys +  1.89 cusr  2.91 csys =  4.80 CPU)
[14:22:00] t/004_pg_xlog_symlink.pl .. ok     9035 ms ( 0.00 usr  0.00 sys +  2.03 cusr  3.02 csys =  5.05 CPU)
[14:22:09] t/005_same_timeline.pl .... ok     8048 ms ( 0.00 usr  0.00 sys +  0.92 cusr  1.29 csys =  2.21 CPU)

which seems quite readable.  So maybe something like this:

     identity                     ... ok      238 ms
     partition_join               ... ok      429 ms
     partition_prune              ... ok      786 ms
     reloptions                   ... ok       94 ms
     hash_part                    ... ok       78 ms
     indexing                     ... ok     1298 ms
     partition_aggregate          ... ok      727 ms
     partition_info               ... ok      110 ms
test event_trigger                ... ok      128 ms
test fast_default                 ... ok      173 ms
test stats                        ... ok      637 ms

which would be

-           status(_(" (%.0f ms)"), INSTR_TIME_GET_MILLISEC(stoptimes[i]));
+           status(_(" %8.0f ms"), INSTR_TIME_GET_MILLISEC(stoptimes[i]));

(times two).

If we're going to keep this, should we enable the prove --timer option as well?

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Peter Eisentraut
Дата:
On 2019-02-15 14:32, Peter Eisentraut wrote:
>      identity                     ... ok      238 ms
>      partition_join               ... ok      429 ms
>      partition_prune              ... ok      786 ms
>      reloptions                   ... ok       94 ms
>      hash_part                    ... ok       78 ms
>      indexing                     ... ok     1298 ms
>      partition_aggregate          ... ok      727 ms
>      partition_info               ... ok      110 ms
> test event_trigger                ... ok      128 ms
> test fast_default                 ... ok      173 ms
> test stats                        ... ok      637 ms

We should also strive to align "FAILED" properly.  This is currently
quite unreadable:

     int4                         ... ok (128 ms)
     int8                         ... FAILED (153 ms)
     oid                          ... ok (163 ms)
     float4                       ... ok (231 ms)

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> On 2019-02-15 14:32, Peter Eisentraut wrote:
>> test event_trigger                ... ok      128 ms
>> test fast_default                 ... ok      173 ms
>> test stats                        ... ok      637 ms

That looks reasonable, although on machines where test runtimes run
into the tens of seconds, there's not going to be nearly as much
whitespace as this example suggests.

> We should also strive to align "FAILED" properly.

Hmm.  The reasonable ways to accomplish that look to be either
(a) pad "ok" to the width of "FAILED", or (b) rely on emitting a tab.
I don't much like either, especially from the localization angle.
One should also note that FAILED often comes along with additional
verbiage, such as "(ignored)" or a note about process exit status;
so I think making such cases line up totally neatly is a lost cause
anyway.

How do you feel about letting it do this:

      int4                         ... ok      128 ms
      int8                         ... FAILED      153 ms
      oid                          ... ok      163 ms
      float4                       ... ok      231 ms

            regards, tom lane


Re: Reporting script runtimes in pg_regress

От
John Naylor
Дата:
On 2/15/19, Peter Eisentraut <peter.eisentraut@2ndquadrant.com> wrote:
> We should also strive to align "FAILED" properly.  This is currently
> quite unreadable:
>
>      int4                         ... ok (128 ms)
>      int8                         ... FAILED (153 ms)
>      oid                          ... ok (163 ms)
>      float4                       ... ok (231 ms)

If I may play devil's advocate, who cares how long it takes a test to
fail? If it's not difficult, leaving the time out for failures would
make them stand out more.

-- 
John Naylor                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:
> If we're going to keep this, should we enable the prove --timer option as well?

As far as that goes: I've found that in some of my older Perl
installations, prove doesn't recognize the --timer switch.
So turning that on would require a configuration probe of some
sort, which seems like more trouble than it's worth.

            regards, tom lane


Re: Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
John Naylor <john.naylor@2ndquadrant.com> writes:
> On 2/15/19, Peter Eisentraut <peter.eisentraut@2ndquadrant.com> wrote:
>> We should also strive to align "FAILED" properly.  This is currently
>> quite unreadable:
>> 
>> int4                         ... ok (128 ms)
>> int8                         ... FAILED (153 ms)
>> oid                          ... ok (163 ms)
>> float4                       ... ok (231 ms)

> If I may play devil's advocate, who cares how long it takes a test to
> fail? If it's not difficult, leaving the time out for failures would
> make them stand out more.

Actually, I'd supposed that that might be useful info, sometimes.
For example it might help you guess whether a timeout had elapsed.

            regards, tom lane


Re: Reporting script runtimes in pg_regress

От
Peter Eisentraut
Дата:
On 2019-02-15 15:54, Tom Lane wrote:
>> We should also strive to align "FAILED" properly.
> Hmm.  The reasonable ways to accomplish that look to be either
> (a) pad "ok" to the width of "FAILED", or (b) rely on emitting a tab.
> I don't much like either, especially from the localization angle.
> One should also note that FAILED often comes along with additional
> verbiage, such as "(ignored)" or a note about process exit status;
> so I think making such cases line up totally neatly is a lost cause
> anyway.

Yeah, not strictly required, but someone might want to play around with
it a bit.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Alvaro Herrera
Дата:
On 2019-Feb-18, Peter Eisentraut wrote:

> On 2019-02-15 15:54, Tom Lane wrote:
> >> We should also strive to align "FAILED" properly.
> > Hmm.  The reasonable ways to accomplish that look to be either
> > (a) pad "ok" to the width of "FAILED", or (b) rely on emitting a tab.
> > I don't much like either, especially from the localization angle.
> > One should also note that FAILED often comes along with additional
> > verbiage, such as "(ignored)" or a note about process exit status;
> > so I think making such cases line up totally neatly is a lost cause
> > anyway.
> 
> Yeah, not strictly required, but someone might want to play around with
> it a bit.

FWIW I don't think we localize pg_regress output currently, so that
argument seems moot ... But I think we can get away with constant four
spaces for now.

If we wanted to get really fancy, for interactive use we could colorize
the output.  (I wonder if there's a way to get browsers to colorize
text/plain output somehow instead of printing the ansi codes).

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Tom Lane
Дата:
Alvaro Herrera <alvherre@2ndquadrant.com> writes:
> On 2019-Feb-18, Peter Eisentraut wrote:
>>> We should also strive to align "FAILED" properly.

>> Yeah, not strictly required, but someone might want to play around with
>> it a bit.

> FWIW I don't think we localize pg_regress output currently, so that
> argument seems moot ... But I think we can get away with constant four
> spaces for now.

I pushed Peter's suggestion for %8.0f; let's live with that for a little
and see if it's still annoying.

            regards, tom lane


Re: Reporting script runtimes in pg_regress

От
Christoph Berg
Дата:
Re: Tom Lane 2019-02-18 <28360.1550506699@sss.pgh.pa.us>
> >>> We should also strive to align "FAILED" properly.
> 
> >> Yeah, not strictly required, but someone might want to play around with
> >> it a bit.
> 
> > FWIW I don't think we localize pg_regress output currently, so that
> > argument seems moot ... But I think we can get away with constant four
> > spaces for now.
> 
> I pushed Peter's suggestion for %8.0f; let's live with that for a little
> and see if it's still annoying.

The ryu changes make postgresql-unit fail quite loudly:

$ cat regression.out
test extension                    ... ok      359 ms
test tables                       ... FAILED      164 ms
test unit                         ... FAILED      867 ms
test binary                       ... ok       20 ms
test unicode                      ... ok       18 ms
test prefix                       ... FAILED       43 ms
test units                        ... FAILED      207 ms
test time                         ... FAILED       99 ms
test temperature                  ... FAILED       22 ms
...

The misalignment annoyed me enough (especially the false alignment
between "ms" on the first row and "164" on the next row) to look into
it. Aligned it looks like this:

test extension                    ... ok          399 ms
test tables                       ... FAILED      190 ms
test unit                         ... FAILED      569 ms
test binary                       ... ok           14 ms
test unicode                      ... ok           15 ms
test prefix                       ... FAILED       44 ms
test units                        ... FAILED      208 ms
test time                         ... FAILED       99 ms
test temperature                  ... FAILED       21 ms
...

It doesn't break translations because it prints the extra spaces
separately.

In run_single_test() (which this output is from), it simply aligns the
output with FAILED. In run_schedule(), there is the 3rd output string
"failed (ignored)" which is considerably longer. I aligned the output
with that, but also made the timestamp field shorter so it's not too
much to the right.

Christoph

Вложения

Re: Reporting script runtimes in pg_regress

От
Peter Eisentraut
Дата:
On 2019-02-21 10:37, Christoph Berg wrote:
> diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
> index a18a6f6c45..8080626e94 100644
> --- a/src/test/regress/pg_regress.c
> +++ b/src/test/regress/pg_regress.c
> @@ -1794,12 +1794,14 @@ run_schedule(const char *schedule, test_function tfunc)
>                  else
>                  {
>                      status(_("FAILED"));
> +                    status("          "); /* align with failed (ignored) */
>                      fail_count++;
>                  }

So an issue here is that in theory "FAILED" etc. are marked for
translation but your spacers do not take that into account.  Personally,
I have no ambition to translate pg_regress, so we could remove all that.
 But it should be done consistently in either case.

I also think we shouldn't worry about the "failed (ignored)" case.  That
never happens, and I don't want to mess up the spacing we have now for
that.  I'd consider removing support for it altogether.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Reporting script runtimes in pg_regress

От
Christoph Berg
Дата:
Re: Peter Eisentraut 2019-03-08 <3eb194cf-b878-1f63-8623-6d6add0ed0b7@2ndquadrant.com>
> On 2019-02-21 10:37, Christoph Berg wrote:
> > diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
> > index a18a6f6c45..8080626e94 100644
> > --- a/src/test/regress/pg_regress.c
> > +++ b/src/test/regress/pg_regress.c
> > @@ -1794,12 +1794,14 @@ run_schedule(const char *schedule, test_function tfunc)
> >                  else
> >                  {
> >                      status(_("FAILED"));
> > +                    status("          "); /* align with failed (ignored) */
> >                      fail_count++;
> >                  }
> 
> So an issue here is that in theory "FAILED" etc. are marked for
> translation but your spacers do not take that into account.  Personally,
> I have no ambition to translate pg_regress, so we could remove all that.
>  But it should be done consistently in either case.

Oh, right. So the way to go would be to use _("FAILED       "), and
ask translators to use the same length.

> I also think we shouldn't worry about the "failed (ignored)" case.  That
> never happens, and I don't want to mess up the spacing we have now for
> that.  I'd consider removing support for it altogether.

You mean removing that case from pg_regress, or removing the alignment
"support"?

Christoph


Re: Reporting script runtimes in pg_regress

От
Alvaro Herrera
Дата:
On 2019-Mar-08, Christoph Berg wrote:

> Re: Peter Eisentraut 2019-03-08 <3eb194cf-b878-1f63-8623-6d6add0ed0b7@2ndquadrant.com>
> > On 2019-02-21 10:37, Christoph Berg wrote:
> > > diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
> > > index a18a6f6c45..8080626e94 100644
> > > --- a/src/test/regress/pg_regress.c
> > > +++ b/src/test/regress/pg_regress.c
> > > @@ -1794,12 +1794,14 @@ run_schedule(const char *schedule, test_function tfunc)
> > >                  else
> > >                  {
> > >                      status(_("FAILED"));
> > > +                    status("          "); /* align with failed (ignored) */
> > >                      fail_count++;
> > >                  }
> > 
> > So an issue here is that in theory "FAILED" etc. are marked for
> > translation but your spacers do not take that into account.  Personally,
> > I have no ambition to translate pg_regress, so we could remove all that.
> >  But it should be done consistently in either case.
> 
> Oh, right. So the way to go would be to use _("FAILED       "), and
> ask translators to use the same length.

Note there's no translation for pg_regress.  All these _() markers are
currently dead code.  It seems hard to become motivated to translate
that kind of program.  I don't think it has much value, myself.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


Re: Re: Reporting script runtimes in pg_regress

От
David Steele
Дата:
Hi Christophe,

On 3/8/19 5:12 PM, Alvaro Herrera wrote:
> On 2019-Mar-08, Christoph Berg wrote:
> 
>> Re: Peter Eisentraut 2019-03-08 <3eb194cf-b878-1f63-8623-6d6add0ed0b7@2ndquadrant.com>
>>> On 2019-02-21 10:37, Christoph Berg wrote:
>>>> diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c
>>>> index a18a6f6c45..8080626e94 100644
>>>> --- a/src/test/regress/pg_regress.c
>>>> +++ b/src/test/regress/pg_regress.c
>>>> @@ -1794,12 +1794,14 @@ run_schedule(const char *schedule, test_function tfunc)
>>>>                   else
>>>>                   {
>>>>                       status(_("FAILED"));
>>>> +                    status("          "); /* align with failed (ignored) */
>>>>                       fail_count++;
>>>>                   }
>>>
>>> So an issue here is that in theory "FAILED" etc. are marked for
>>> translation but your spacers do not take that into account.  Personally,
>>> I have no ambition to translate pg_regress, so we could remove all that.
>>>   But it should be done consistently in either case.
>>
>> Oh, right. So the way to go would be to use _("FAILED       "), and
>> ask translators to use the same length.
> 
> Note there's no translation for pg_regress.  All these _() markers are
> currently dead code.  It seems hard to become motivated to translate
> that kind of program.  I don't think it has much value, myself.

This patch has been "Waiting on Author" since March 8th.  Do you know 
when you'll have a new version ready?

Regards,
-- 
-David
david@pgmasters.net


Re: Re: Reporting script runtimes in pg_regress

От
Christoph Berg
Дата:
Re: David Steele 2019-03-20 <8a85bece-b18f-0433-acf3-d106b31f0271@pgmasters.net>
> > > Oh, right. So the way to go would be to use _("FAILED       "), and
> > > ask translators to use the same length.
> > 
> > Note there's no translation for pg_regress.  All these _() markers are
> > currently dead code.  It seems hard to become motivated to translate
> > that kind of program.  I don't think it has much value, myself.
> 
> This patch has been "Waiting on Author" since March 8th.  Do you know when
> you'll have a new version ready?

Here is a new revision that blank-pads "ok" to the length of "FAILED".

Christoph

Вложения

Re: Reporting script runtimes in pg_regress

От
Peter Eisentraut
Дата:
On 2019-03-21 12:51, Christoph Berg wrote:
> Re: David Steele 2019-03-20 <8a85bece-b18f-0433-acf3-d106b31f0271@pgmasters.net>
>>>> Oh, right. So the way to go would be to use _("FAILED       "), and
>>>> ask translators to use the same length.
>>>
>>> Note there's no translation for pg_regress.  All these _() markers are
>>> currently dead code.  It seems hard to become motivated to translate
>>> that kind of program.  I don't think it has much value, myself.
>>
>> This patch has been "Waiting on Author" since March 8th.  Do you know when
>> you'll have a new version ready?
> 
> Here is a new revision that blank-pads "ok" to the length of "FAILED".

committed

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services