[Peter Eisentraut <peter.eisentraut@2ndquadrant.com>]

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