[Michael Paquier <michael@paquier.xyz>]

On Wed, Jun 23, 2021 at 10:01:28PM +0200, Fabien COELHO wrote:
> Thanks for the hint! Why not, having the ability to collect data is a good
> thing, so attached v10 does that. If something go wrong, the TODO section
> could be extended around all calls.

+check_pgbench_logs($bdir, '001_pgbench_log_1', $nthreads, 1, 3,
+   qr{^\d{10,} \d{1,2} \d+ \d+ \d+ \d+ \d+ \d+ \d+ \d+ \d+$});
FWIW, I am still seeing problems with the regex pattern you are using
here, because this fails to detect the number of fields we should have
generated here, for one.  If you are not convinced, just run your new
test and extend or reduce the amount of data generated by logAgg() in
your patch: the tests will still pass.

So I have investigated this stuff in details.  The regular expressions
are correctly shaped, but the use of grep() in check_pgbench_logs()
seems to be incorrect.

For example, let's take an aggregate report generated by your new
test:
"1624498086 13 27632 60597490 1683 2853 3227 883179 120 386 123"
Here are some extra ones, shorter and longer:
"1624498086 13 27632 60597490 1683 2853 3227 8831";
"1624498086 13 27632 60597490 1683 2853 3227 883179 120 386 123 123";

Using grep() with "$re" results in all the fields matching.  Using on
the contrary "/$re/" in grep(), like list_files(), would only match
the first one, which is correct.  Please see attached a small script
to show my point, called perl_grep.pl.

With this issue fixed, I have bumped into what looks like a different
bug in the tests.  001_pgbench_log_2 uses pgbench with 2 clients, but
expects only patterns in the logs where the first column value uses
only 0.  With two clients, those first values can be either 0 or 1 due
to the client ID set.

It seems to me that we had better fix this issue and back-patch where
this has been introduced so as we have exact match checks with the log
formarts, no?  Please see the attached.

Thoughts?
--
Michael

Attachments:

perl_grep.pl (text/x-perl, 830B) download
use strict;
use warnings;
use Test::More;

my $field_correct = "1624498086 13 27632 60597490 1683 2853 3227 883179 120 386 123";
my $field_broken_short = "1624498086 13 27632 60597490 1683 2853 3227 8831";
my $field_broken_long = "1624498086 13 27632 60597490 1683 2853 3227 883179 120 386 123 123";
my $re = qr{^\d{10,} \d{1,2} \d+ \d+ \d+ \d+ \d+ \d+ \d+ \d+ \d+$};
my @array_broken = ($field_correct, $field_broken_short, $field_broken_long);
my @array_correct = ($field_correct, $field_correct);

# All the element should match here.
ok(grep($re, @array_correct) == @array_correct, 're+array_correct');
ok(grep(/$re/, @array_correct) == @array_correct, '/re/+array_correct');

# Only one element should match here.
ok(grep($re, @array_broken) == 1, 're+array_broken');
ok(grep(/$re/, @array_broken) == 1, '/re/+array_broken');

pgbench-tap-fix.patch (text/x-diff, 807B) download
diff --git a/src/bin/pgbench/t/001_pgbench_with_server.pl b/src/bin/pgbench/t/001_pgbench_with_server.pl
index 923203ea51..ef8e40240b 100644
--- a/src/bin/pgbench/t/001_pgbench_with_server.pl
+++ b/src/bin/pgbench/t/001_pgbench_with_server.pl
@@ -1194,7 +1194,7 @@ sub check_pgbench_logs
 			my $clen     = @contents;
 			ok( $min <= $clen && $clen <= $max,
 				"transaction count for $log ($clen)");
-			ok( grep($re, @contents) == $clen,
+			ok( grep(/$re/, @contents) == $clen,
 				"transaction format for $prefix");
 			close $fh or die "$@";
 		};
@@ -1213,7 +1213,7 @@ pgbench(
 	"--log-prefix=$bdir/001_pgbench_log_2");
 
 check_pgbench_logs($bdir, '001_pgbench_log_2', 1, 8, 92,
-	qr{^0 \d{1,2} \d+ \d \d+ \d+$});
+	qr{^{0,1} \d{1,2} \d+ \d \d+ \d+$});
 
 # check log file in some detail
 pgbench(

  signature.asc (application/pgp-signature, 832B) download