rdelaage
/
postgresql
mirror of https://git.postgresql.org/git/postgresql.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Add timestamp and elapsed time decorations to TAP test logs 

These apply to traces from Test::More functions such as ok(), is(),
diag() and note(). Output from other sources (e.g. external programs
such a initdb) is not affected. The elapsed time is the time since the
last such trace (or the beginning of the test in the first case). Times
and timestamps are at millisecond precision.

Discussion: https://postgr.es/m/20220401172150.rsycz4lrn7ewruil@alap3.anarazel.de
This commit is contained in:
Andrew Dunstan 2022-04-10 08:46:12 -04:00
parent 7b735f8b52
commit 3b0a42e74e
No known key found for this signature in database
GPG Key ID: 99FA7FCB59FC3B81
1 changed files with 29 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

30
src/test/perl/PostgreSQL/Test/SimpleTee.pm
View File

@ -10,10 +10,32 @@
# method is currently implemented; that's all we need. We don't want to
# depend on IO::Tee just for this.
# The package is enhanced to add timestamp and elapsed time decorations to
# the log file traces sent through this interface from Test::More functions
# (ok, is, note, diag etc.). Elapsed time is shown as the time since the last
# log trace.
package PostgreSQL::Test::SimpleTee;
use strict;
use warnings;
use Time::HiRes qw(time);
my $last_time;
BEGIN { $last_time = time; }
sub _time_str
{
my $tm = time;
my $diff = $tm - $last_time;
$last_time = $tm;
my ($sec, $min, $hour) = localtime($tm);
my $msec = int(1000 * ($tm - int($tm)));
return sprintf("[%.2d:%.2d:%.2d.%.3d](%.3fs) ",
$hour, $min, $sec, $msec, $diff);
}
sub TIEHANDLE
{
my $self = shift;
@ -24,10 +46,16 @@ sub PRINT
{
my $self = shift;
my $ok = 1;
# The first file argument passed to tiehandle in PostgreSQL::Test::Utils is
# the original stdout, which is what PROVE sees. Additional decorations
# confuse it, so only put out the time string on files after the first.
my $skip = 1;
my $ts = _time_str;
for my $fh (@$self)
{
print $fh @_ or $ok = 0;
print $fh ($skip ? "" : $ts), @_ or $ok = 0;
$fh->flush or $ok = 0;
$skip = 0;
}
return $ok;
}