Include pg_test_timing's full output in the TAP test log.
authorTom Lane <tgl@sss.pgh.pa.us>
Wed, 24 Sep 2025 16:08:55 +0000 (12:08 -0400)
committerTom Lane <tgl@sss.pgh.pa.us>
Wed, 24 Sep 2025 16:09:11 +0000 (12:09 -0400)
We were already doing a short (1-second) pg_test_timing run during
check-world and buildfarm runs.  But we weren't doing anything
with the result except for a basic regex-based sanity check.
Collecting that output from buildfarm runs is seeming very
attractive though, because it would help us determine what sort
of timing resolution is available on supported platforms.
It's not very long, so let's just note it verbatim in the TAP log.

Discussion: https://postgr.es/m/3321785.1758728271@sss.pgh.pa.us

src/bin/pg_test_timing/t/001_basic.pl

index 9912acc052a29f37d949ed8c442a2deef6ff0e7f..040e62247ee1bd8a0bcd24192f1b8200c346b20a 100644 (file)
@@ -33,14 +33,23 @@ command_fails_like(
 #########################################
 # We obviously can't check for specific output, but we can
 # do a simple run and make sure it produces something.
-
-command_like(
-   [ 'pg_test_timing', '--duration' => '1' ],
+# Also, note the output in the log for data collection purposes.
+
+my $cmd = [ 'pg_test_timing', '--duration' => '1' ];
+my ($stdout, $stderr);
+print("# Running: " . join(" ", @{$cmd}) . "\n");
+my $result = IPC::Run::run $cmd, '>' => \$stdout, '2>' => \$stderr;
+is($result, 1, "pg_test_timing: exit code 0");
+is($stderr, '', "pg_test_timing: no stderr");
+like(
+   $stdout,
    qr/
 \QTesting timing overhead for 1 second.\E.*
 \QHistogram of timing durations:\E.*
 \QObserved timing durations up to 99.9900%:\E
 /sx,
-   'pg_test_timing: sanity check');
+   'pg_test_timing: stdout passes sanity check');
+
+note "pg_test_timing results:\n$stdout\n";
 
 done_testing();