Thread: Add test of pg_prewarm extenion

Hi hackers,
I wrote a test for pg_prewarm extension. and I wrote it with the aim of improving test coverage, and feedback is always
welcome.

---
Regards
DongWook Lee

On Wed, Jun 29, 2022 at 02:38:12PM +0900, Dong Wook Lee wrote:
> Hi hackers,
> I wrote a test for pg_prewarm extension. and I wrote it with the aim of improving test coverage, and feedback is
alwayswelcome.
 

The test fails when USE_PREFETCH isn't defined.
http://cfbot.cputube.org/dongwook-lee.html

You can accommodate that by adding an "alternate" output file, named like
pg_prewarm_0.out

BTW, you can test your patches the same as cfbot does (before mailing the list)
on 4 OSes by pushing a branch to a github account.  See ./src/tools/ci/README

-- 
Justin

Justin Pryzby <pryzby@telsasoft.com> writes:
> On Wed, Jun 29, 2022 at 02:38:12PM +0900, Dong Wook Lee wrote:
>> I wrote a test for pg_prewarm extension. and I wrote it with the aim of improving test coverage, and feedback is
alwayswelcome. 

> The test fails when USE_PREFETCH isn't defined.
> You can accommodate that by adding an "alternate" output file, named like
> pg_prewarm_0.out

FWIW, I'd tend to just not bother exercising the prefetch case.
It doesn't seem worth maintaining an alternate expected-file for that,
since it's not meaningfully different from the other code paths
as far as this code is concerned, and testing PrefetchBuffer itself
isn't the responsibility of this test.

I tried this patch locally and was disturbed to see that the
code coverage of autoprewarm.c is still very low.  It looks like
apw_load_buffers never reaches any of the actual prewarming code,
because it never successfully opens AUTOPREWARM_FILE.  This seems a
bit odd to me, but maybe it's because you start and immediately stop
the database without causing it to do anything that would populate
shared buffers?  This bit:

+ok ($logfile =~
+    qr/autoprewarm successfully prewarmed 0 of 1 previously-loaded blocks/);

is certainly a red flag that little of interest happened.

Keep in mind also that the logfile accumulates over stops and
restarts.  As you've coded this test, you don't know which DB start
emitted the matching line, so the test proves a lot less than it
ought to.

I wonder also about race conditions.  On fast machines, or those
with weird schedulers, the test script might reach slurp_file
before autoprewarm has had a chance to emit the log entry you want.

            regards, tom lane

Hi,
First of all, thank you for your feedback.

2022년 7월 31일 (일) 오전 3:25, Tom Lane <tgl@sss.pgh.pa.us>님이 작성:
>
> Justin Pryzby <pryzby@telsasoft.com> writes:
> > On Wed, Jun 29, 2022 at 02:38:12PM +0900, Dong Wook Lee wrote:
> >> I wrote a test for pg_prewarm extension. and I wrote it with the aim of improving test coverage, and feedback is
alwayswelcome. 
>
> > The test fails when USE_PREFETCH isn't defined.
> > You can accommodate that by adding an "alternate" output file, named like
> > pg_prewarm_0.out
>
> FWIW, I'd tend to just not bother exercising the prefetch case.
> It doesn't seem worth maintaining an alternate expected-file for that,
> since it's not meaningfully different from the other code paths
> as far as this code is concerned, and testing PrefetchBuffer itself
> isn't the responsibility of this test.
>
> I tried this patch locally and was disturbed to see that the
> code coverage of autoprewarm.c is still very low.  It looks like
> apw_load_buffers never reaches any of the actual prewarming code,
> because it never successfully opens AUTOPREWARM_FILE.  This seems a
> bit odd to me, but maybe it's because you start and immediately stop
> the database without causing it to do anything that would populate
> shared buffers?  This bit:
>
> +ok ($logfile =~
> +    qr/autoprewarm successfully prewarmed 0 of 1 previously-loaded blocks/);
>
> is certainly a red flag that little of interest happened.

I think it was because I didn't have much data either.
After adding data, coverage increased significantly. (11.6% -> 73.6%)

>
> Keep in mind also that the logfile accumulates over stops and
> restarts.  As you've coded this test, you don't know which DB start
> emitted the matching line, so the test proves a lot less than it
> ought to.
>
> I wonder also about race conditions.  On fast machines, or those
> with weird schedulers, the test script might reach slurp_file
> before autoprewarm has had a chance to emit the log entry you want.

I have no idea how to deal with race conditions.
Does anybody know how to deal with this?

On Mon, Aug 1, 2022 at 5:16 PM Dong Wook Lee <sh95119@gmail.com> wrote:
>
> > Keep in mind also that the logfile accumulates over stops and
> > restarts.  As you've coded this test, you don't know which DB start
> > emitted the matching line, so the test proves a lot less than it
> > ought to.
> >
> > I wonder also about race conditions.  On fast machines, or those
> > with weird schedulers, the test script might reach slurp_file
> > before autoprewarm has had a chance to emit the log entry you want.
>
> I have no idea how to deal with race conditions.
> Does anybody know how to deal with this?

Couldn't you use $node->wait_for_log() instead?

Julien Rouhaud <rjuju123@gmail.com> writes:
> On Mon, Aug 1, 2022 at 5:16 PM Dong Wook Lee <sh95119@gmail.com> wrote:
>> I have no idea how to deal with race conditions.
>> Does anybody know how to deal with this?

> Couldn't you use $node->wait_for_log() instead?

Yeah.  The standard usage pattern for that also covers the issue
of not re-examining prior chunks of the log.

            regards, tom lane

Thank you for letting me know.
I edited my patch with `wait_for_log()`.

2022년 8월 1일 (월) 오후 6:55, Julien Rouhaud <rjuju123@gmail.com>님이 작성:
>
> On Mon, Aug 1, 2022 at 5:16 PM Dong Wook Lee <sh95119@gmail.com> wrote:
> >
> > > Keep in mind also that the logfile accumulates over stops and
> > > restarts.  As you've coded this test, you don't know which DB start
> > > emitted the matching line, so the test proves a lot less than it
> > > ought to.
> > >
> > > I wonder also about race conditions.  On fast machines, or those
> > > with weird schedulers, the test script might reach slurp_file
> > > before autoprewarm has had a chance to emit the log entry you want.
> >
> > I have no idea how to deal with race conditions.
> > Does anybody know how to deal with this?
>
> Couldn't you use $node->wait_for_log() instead?

2022년 8월 1일 (월) 오후 11:33, Dong Wook Lee <sh95119@gmail.com>님이 작성:
>
> Thank you for letting me know.
> I edited my patch with `wait_for_log()`.
>
> 2022년 8월 1일 (월) 오후 6:55, Julien Rouhaud <rjuju123@gmail.com>님이 작성:
> >
> > On Mon, Aug 1, 2022 at 5:16 PM Dong Wook Lee <sh95119@gmail.com> wrote:
> > >
> > > > Keep in mind also that the logfile accumulates over stops and
> > > > restarts.  As you've coded this test, you don't know which DB start
> > > > emitted the matching line, so the test proves a lot less than it
> > > > ought to.
> > > >
> > > > I wonder also about race conditions.  On fast machines, or those
> > > > with weird schedulers, the test script might reach slurp_file
> > > > before autoprewarm has had a chance to emit the log entry you want.
> > >
> > > I have no idea how to deal with race conditions.
> > > Does anybody know how to deal with this?
> >
> > Couldn't you use $node->wait_for_log() instead?

Please forgive my carelessness.
After trimming the code a little more, I sent the patch again.

Dong Wook Lee <sh95119@gmail.com> writes:
>>> Couldn't you use $node->wait_for_log() instead?

> After trimming the code a little more, I sent the patch again.

This is much better, but still has some issues:

* The prefetch test might as well not be there, because
check_pg_config("#USE_PREFETCH 1") will never succeed: there is no
such string in pg_config.h.  I don't actually see any good
(future-proof) way to determine whether USE_PREFETCH is enabled from
the available configuration data.  After some thought I concluded we
could just try the function and accept either success or "prefetch is
not supported by this build".

* The script had no actual tests, so far as Test::More is concerned.
I'm not sure that that causes any real problems, but I reformulated
the pg_prewarm() tests to verify that a sane-looking result is
returned.

* I also added a test of autoprewarm_dump_now(), just to get the
line coverage count over the magic 75% figure.

* You left out a .gitignore file.

I made some other cosmetic changes (mostly, running it through
pgperltidy) and pushed it.  Thanks for the patch!

            regards, tom lane