Horton

Thread

Commits

  1. Cleanup some code related to pgbench log checks in TAP tests

  2. Add more debugging information with log checks in TAP tests of pgbench

  3. Fix pattern matching logic for logs in TAP tests of pgbench

  1. pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-24T21:54:51Z

    Fix pattern matching logic for logs in TAP tests of pgbench

The logic checking for the format of per-thread logs used grep() with
directly "$re", which would cause the test to consider all the logs as
a match without caring about their format at all.  Using "/$re/" makes
grep() perform a regex test, which is what we want here.

While on it, improve some of the tests to be more picky with the
patterns expected and add more comments to describe the tests.

Issue discovered while digging into a separate patch.

Author: Fabien Coelho, Michael Paquier
Discussion: https://postgr.es/m/YNPsPAUoVDCpPOGk@paquier.xyz
Backpatch-through: 11

Branch
------
master

Details
-------
https://git.postgresql.org/pg/commitdiff/c13585fe9e55813cf9feac67fe7b65d3a78fff92

Modified Files
--------------
src/bin/pgbench/t/001_pgbench_with_server.pl | 23 ++++++++++++++---------
1 file changed, 14 insertions(+), 9 deletions(-)

  2. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-24T23:51:19Z

    On Thu, Jun 24, 2021 at 09:54:51PM +0000, Michael Paquier wrote:
> Fix pattern matching logic for logs in TAP tests of pgbench
> 
> The logic checking for the format of per-thread logs used grep() with
> directly "$re", which would cause the test to consider all the logs as
> a match without caring about their format at all.  Using "/$re/" makes
> grep() perform a regex test, which is what we want here.
> 
> While on it, improve some of the tests to be more picky with the
> patterns expected and add more comments to describe the tests.
> 
> Issue discovered while digging into a separate patch.

fairywren does not like that:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=fairywren&dt=2021-06-24%2022%3A36%3A14

not ok 302 - transaction format for 001_pgbench_log_2
not ok 311 - transaction format for 001_pgbench_log_3

I am not sure if this is a pre-existing bug in pgbench itself
regarding the way we generate the logs or an issue with fairywren's
perl installation.

Andrew, what's the format of the per-thread logs generated on this
host when running the commands?  I'd bet that the checks for the
client IDs are right, but that some parts of the regex are too picky
when it comes to this host.
--
Michael

  3. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-25T00:26:21Z

    (Forgot to add Andrew in CC, now done)

On Fri, Jun 25, 2021 at 08:51:19AM +0900, Michael Paquier wrote:
> Andrew, what's the format of the per-thread logs generated on this
> host when running the commands?  I'd bet that the checks for the
> client IDs are right, but that some parts of the regex are too picky
> when it comes to this host.

I have tested that on my own Windows host using MSVC and Active Perl,
and those tests pass.  I am not sure what's happening here.  A simple
way to figure out what's going on would be to make the tests more
talkative and show up the logs that don't match.
--
Michael

  4. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Andrew Dunstan <andrew@dunslane.net> — 2021-06-25T01:36:53Z

    On 6/24/21 8:26 PM, Michael Paquier wrote:
> (Forgot to add Andrew in CC, now done)
>
> On Fri, Jun 25, 2021 at 08:51:19AM +0900, Michael Paquier wrote:
>> Andrew, what's the format of the per-thread logs generated on this
>> host when running the commands?  I'd bet that the checks for the
>> client IDs are right, but that some parts of the regex are too picky
>> when it comes to this host.
> I have tested that on my own Windows host using MSVC and Active Perl,
> and those tests pass.  I am not sure what's happening here.  A simple
> way to figure out what's going on would be to make the tests more
> talkative and show up the logs that don't match.



That's not really an equivalent test. I'm taking a look


cheers


andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

  5. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-25T01:53:59Z

    On Thu, Jun 24, 2021 at 09:36:53PM -0400, Andrew Dunstan wrote:
> That's not really an equivalent test. I'm taking a look

Thanks!
--
Michael

  6. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Andrew Dunstan <andrew@dunslane.net> — 2021-06-25T02:12:44Z

    On 6/24/21 9:53 PM, Michael Paquier wrote:
> On Thu, Jun 24, 2021 at 09:36:53PM -0400, Andrew Dunstan wrote:
>> That's not really an equivalent test. I'm taking a look
> Thanks!




There's a whole lot wrong with this code. To start with, why is that
unchecked eval there. And why is it reading in log files on its own
instead of using TestLib::slurp_file, which, among other things,
normalizes line endings? There's a very good chance that this latter is
the issue. It only affects msys which is why you didn't see an issue on
MSVC. And also, why does it carefully unlink the log files so that any
trace of what's gone wrong is deleted?


Based on the little I've seen this file needs a serious code review.


cheers


andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

  7. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Andrew Dunstan <andrew@dunslane.net> — 2021-06-25T02:26:18Z

    On 6/24/21 10:12 PM, Andrew Dunstan wrote:
> On 6/24/21 9:53 PM, Michael Paquier wrote:
>> On Thu, Jun 24, 2021 at 09:36:53PM -0400, Andrew Dunstan wrote:
>>> That's not really an equivalent test. I'm taking a look
>> Thanks!
>
>
>
> There's a whole lot wrong with this code. To start with, why is that
> unchecked eval there. And why is it reading in log files on its own
> instead of using TestLib::slurp_file, which, among other things,
> normalizes line endings? There's a very good chance that this latter is
> the issue. It only affects msys which is why you didn't see an issue on
> MSVC. And also, why does it carefully unlink the log files so that any
> trace of what's gone wrong is deleted?
>
>
> Based on the little I've seen this file needs a serious code review.



... and there's the error:


check_pgbench_logs($bdir, '001_pgbench_log_2', 1, 8, 92,
    qr{^[01] \d{1,2} \d+ \d \d+ \d+$});


and one further down the same.


Since the file isn't read in using slurp_file, that $ won't match
because the lines will end \r\n instead of \n.


cheers


andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

  8. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-25T03:08:29Z

    On Thu, Jun 24, 2021 at 10:26:18PM -0400, Andrew Dunstan wrote:
> Since the file isn't read in using slurp_file, that $ won't match
> because the lines will end \r\n instead of \n.

I did not remember this one with Msys, thanks.  I am not sure that
there is any need for an eval block here actually once you remove
open()?  What do you think about something like the attached?
--
Michael

  9. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Andrew Dunstan <andrew@dunslane.net> — 2021-06-25T10:12:09Z

    On 6/24/21 11:08 PM, Michael Paquier wrote:
> On Thu, Jun 24, 2021 at 10:26:18PM -0400, Andrew Dunstan wrote:
>> Since the file isn't read in using slurp_file, that $ won't match
>> because the lines will end \r\n instead of \n.
> I did not remember this one with Msys, thanks.  I am not sure that
> there is any need for an eval block here actually once you remove
> open()?  What do you think about something like the attached?


+        # On Msys, filter out any CRLF.
+        $contents_raw =~ s/\r\n/\n/g if $Config{osname} eq 'msys';

This is completely redundant. The whole point is that slurp_file does
exactly this for you.


+        my @contents = split("\n", $contents_raw);

Probably more idiomatic to write split(/\n/,$contents_raw), or
split(/^/, $contents_raw) if you want to keep the line feeds.


cheers


andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

  10. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-25T12:24:23Z

    On Fri, Jun 25, 2021 at 06:12:09AM -0400, Andrew Dunstan wrote:
> +        # On Msys, filter out any CRLF.
> +        $contents_raw =~ s/\r\n/\n/g if $Config{osname} eq 'msys';
> 
> This is completely redundant. The whole point is that slurp_file does
> exactly this for you.

Thanks.  I have managed to duplicate that.

> +        my @contents = split("\n", $contents_raw);
> 
> Probably more idiomatic to write split(/\n/,$contents_raw), or
> split(/^/, $contents_raw) if you want to keep the line feeds.

I have gone with the solution that removes the newlines.  This does
not change the pattern checks, and that makes printing entries not
matching a bit cleaner.

Thanks a lot for the investigation!
--
Michael

  11. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Fabien COELHO <coelho@cri.ensmp.fr> — 2021-06-26T06:47:34Z

    Hello Andrew & Michaël,

My 0.02€:

> There's a whole lot wrong with this code. To start with, why is that
> unchecked eval there.

Yep. The idea was that other tests would go on being collected eg if the 
file is not found, but it should have been checked anyway.

> And why is it reading in log files on its own instead of using 
> TestLib::slurp_file, which, among other things, normalizes line endings?

Indeed.

However, if slurp_file fails it raises an exception and aborts the whole 
TAP unexpectedly, which is pretty unclean. So I'd suggest to keep the 
eval, as attached. I tested it by changing the file name so that the slurp 
fails.

> There's a very good chance that this latter is the issue. It only 
> affects msys which is why you didn't see an issue on MSVC. And also, why 
> does it carefully unlink the log files so that any trace of what's gone 
> wrong is deleted?

> Based on the little I've seen this file needs a serious code review.

Probably: My very old perl expertise is fading away because I'm not using 
it much these days. Cannot say I miss it:-)

-- 
Fabien.

  12. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Andrew Dunstan <andrew@dunslane.net> — 2021-06-26T15:01:07Z

    On 6/26/21 2:47 AM, Fabien COELHO wrote:
>
> Hello Andrew & Michaël,
>
> My 0.02€:
>
>> There's a whole lot wrong with this code. To start with, why is that
>> unchecked eval there.
>
> Yep. The idea was that other tests would go on being collected eg if
> the file is not found, but it should have been checked anyway.
>
>> And why is it reading in log files on its own instead of using
>> TestLib::slurp_file, which, among other things, normalizes line endings?
>
> Indeed.
>
> However, if slurp_file fails it raises an exception and aborts the
> whole TAP unexpectedly, which is pretty unclean. So I'd suggest to
> keep the eval, as attached. I tested it by changing the file name so
> that the slurp fails.


Seem quite unnecessary. We haven't found that to be an issue elsewhere
in the code where slurp_file is used. And in the present case we know
the file exists because we got its name from list_files().


cheers


andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com

  13. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Fabien COELHO <coelho@cri.ensmp.fr> — 2021-06-26T16:08:19Z

    >> However, if slurp_file fails it raises an exception and aborts the
>> whole TAP unexpectedly, which is pretty unclean. So I'd suggest to
>> keep the eval, as attached. I tested it by changing the file name so
>> that the slurp fails.
>
> Seem quite unnecessary. We haven't found that to be an issue elsewhere
> in the code where slurp_file is used. And in the present case we know
> the file exists because we got its name from list_files().

Fine with me!

-- 
Fabien.

  14. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Michael Paquier <michael@paquier.xyz> — 2021-06-27T01:22:24Z

    On Sat, Jun 26, 2021 at 11:01:07AM -0400, Andrew Dunstan wrote:
> On 6/26/21 2:47 AM, Fabien COELHO wrote:
>> However, if slurp_file fails it raises an exception and aborts the
>> whole TAP unexpectedly, which is pretty unclean. So I'd suggest to
>> keep the eval, as attached. I tested it by changing the file name so
>> that the slurp fails.
> 
> Seem quite unnecessary. We haven't found that to be an issue elsewhere
> in the code where slurp_file is used. And in the present case we know
> the file exists because we got its name from list_files().

Agreed.  That's an exchange between a hard failure mid-test and a
failure while letting the whole test run.  Here, we expect the test to
find the log file all the time, so a hard failure does not sound like
a bad thing to me either.
--
Michael

  15. Re: pgsql: Fix pattern matching logic for logs in TAP tests of pgbench

    Fabien COELHO <coelho@cri.ensmp.fr> — 2021-06-27T05:48:25Z

    >> Seem quite unnecessary. We haven't found that to be an issue elsewhere
>> in the code where slurp_file is used. And in the present case we know
>> the file exists because we got its name from list_files().
>
> Agreed.  That's an exchange between a hard failure mid-test and a
> failure while letting the whole test run.  Here, we expect the test to
> find the log file all the time, so a hard failure does not sound like
> a bad thing to me either.

Ok, fine with me!

-- 
Fabien.