Subject: Re: gcov coverage data not full with immediate stop
To: Alvaro Herrera <alvherre@2ndquadrant.com>
Cc: pgsql-hackers <pgsql-hackers@postgresql.org>
References: <20200511034243.GA5671@alvherre.pgsql>
From: Alexander Lakhin <exclusion@gmail.com>
Message-ID: <445c1dd9-bb8a-3153-04b2-40ba97be87b1@gmail.com>
Date: Mon, 11 May 2020 12:00:00 +0300
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:68.0) Gecko/20100101
 Thunderbird/68.7.0
MIME-Version: 1.0
In-Reply-To: <20200511034243.GA5671@alvherre.pgsql>
Content-Type: multipart/mixed;
 boundary="------------1910B4EA4F043C759AC5829B"
Content-Language: en-US
Precedence: bulk

This is a multi-part message in MIME format.
--------------1910B4EA4F043C759AC5829B
Content-Type: multipart/alternative;
 boundary="------------38E63F6B61347BA1EB8D3F9C"


--------------38E63F6B61347BA1EB8D3F9C
Content-Type: text/plain; charset=windows-1252
Content-Transfer-Encoding: 8bit

Hello Alvaro,
11.05.2020 06:42, Alvaro Herrera wrote:
> (Strangely, I was just thinking about these branches of mine as I
> closed my week last Friday...)
>
> On 2020-May-10, Alexander Lakhin wrote:
>
>> So if we want to make the coverage reports more precise, I see the three
>> ways:
>> 1. Change the stop mode in teardown_node to fast (probably only when
>> configured with --enable-coverage);
>> 2. Explicitly stop nodes in TAP tests (where it's important) -- seems
>> too tedious and troublesome;
>> 3. Explicitly call __gcov_flush in SIGQUIT handler (quickdie)?
> I tried your idea 3 a long time ago and my experiments didn't show an
> increase in coverage [1].  But I like this idea the best, and maybe I
> did something wrong.  Attached is the patch I had (on top of
> fc115d0f9fc6), but I don't know if it still applies.
Thanks for the reference to that discussion and your patch.
As I see the issue with that patch is that quickdie() is not the only
SIGQUIT handler. When a backend is interrupted with SIGQUIT, it's
exiting in SignalHandlerForCrashExit().
In fact if I only add __gcov_flush() in SignalHandlerForCrashExit(), it
raises test coverage for `make check -C src/test/recovery/` from
106198 lines/6319 functions
to
106420 lines/6328 functions

It's not yet clear to me what happens when __gcov_flush() called inside
__gcov_flush().
The test coverage changes to:
108432 lines/5417 functions
(number of function calls decreased)
And for example in coverage/src/backend/utils/cache/catcache.c.gcov.html
I see
     147           8 : int2eqfast(Datum a, Datum b)
...
     153           0 : int2hashfast(Datum datum)
but without __gcov_flush in quickdie() we have:
     147       78038 : int2eqfast(Datum a, Datum b)
...
     153      255470 : int2hashfast(Datum datum)
So it needs more investigation.

But I can confirm that calling __gcov_flush() in
SignalHandlerForCrashExit() really improves a code coverage report.
I tried to develop a test to elevate a coverage for gist:
https://coverage.postgresql.org/src/backend/access/gist/gistxlog.c.gcov.html
(Please look at the attached test if it could be interesting.)
and came to this issue with a coverage. I tried to play with
GCOV_PREFIX, but without luck.
Yesterday I found the more recent discussion:
https://www.postgresql.org/message-id/flat/44ecae53-9861-71b7-1d43-4658acc52519%402ndquadrant.com#d02e2e61212831fbceadf290637913a0
(where probably the same problem came out).

Finally I've managed to get an expected coverage when I performed
$node_standby->stop() (but __gcov_flush() in SignalHandlerForCrashExit()
helps too).

Best regards,
Alexander

--------------38E63F6B61347BA1EB8D3F9C
Content-Type: text/html; charset=windows-1252
Content-Transfer-Encoding: 8bit

<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html;
      charset=windows-1252">
  </head>
  <body>
    <div class="moz-cite-prefix">Hello Alvaro,<br>
      11.05.2020 06:42, Alvaro Herrera wrote:<br>
    </div>
    <blockquote type="cite"
      cite="mid:20200511034243.GA5671@alvherre.pgsql">
      <pre class="moz-quote-pre" wrap="">(Strangely, I was just thinking about these branches of mine as I
closed my week last Friday...)

On 2020-May-10, Alexander Lakhin wrote:

</pre>
      <blockquote type="cite">
        <pre class="moz-quote-pre" wrap="">So if we want to make the coverage reports more precise, I see the three
ways:
1. Change the stop mode in teardown_node to fast (probably only when
configured with --enable-coverage);
2. Explicitly stop nodes in TAP tests (where it's important) -- seems
too tedious and troublesome;
3. Explicitly call __gcov_flush in SIGQUIT handler (quickdie)?
</pre>
      </blockquote>
      <pre class="moz-quote-pre" wrap="">
I tried your idea 3 a long time ago and my experiments didn't show an
increase in coverage [1].  But I like this idea the best, and maybe I
did something wrong.  Attached is the patch I had (on top of
fc115d0f9fc6), but I don't know if it still applies.</pre>
    </blockquote>
    Thanks for the reference to that discussion and your patch.<br>
    As I see the issue with that patch is that quickdie() is not the
    only SIGQUIT handler. When a backend is interrupted with SIGQUIT,
    it's exiting in SignalHandlerForCrashExit().<br>
    In fact if I only add __gcov_flush() in SignalHandlerForCrashExit(),
    it raises test coverage for `make check -C src/test/recovery/` from<br>
    106198 lines/6319 functions<br>
    to<br>
    106420 lines/6328 functions<br>
    <br>
    It's not yet clear to me what happens when __gcov_flush() called
    inside __gcov_flush().<br>
    The test coverage changes to:<br>
    108432 lines/5417 functions<br>
    (number of function calls decreased)<br>
    And for example in
    coverage/src/backend/utils/cache/catcache.c.gcov.html I see<br>
         147           8 : int2eqfast(Datum a, Datum b)<br>
    ...<br>
         153           0 : int2hashfast(Datum datum)<br>
    but without __gcov_flush in quickdie() we have:<br>
         147       78038 : int2eqfast(Datum a, Datum b)<br>
    ...<br>
         153      255470 : int2hashfast(Datum datum)<br>
    So it needs more investigation.<br>
    <br>
    But I can confirm that calling __gcov_flush() in
    SignalHandlerForCrashExit() really improves a code coverage report.<br>
    I tried to develop a test to elevate a coverage for gist:<br>
<a class="moz-txt-link-freetext" href="https://coverage.postgresql.org/src/backend/access/gist/gistxlog.c.gcov.html">https://coverage.postgresql.org/src/backend/access/gist/gistxlog.c.gcov.html</a><br>
    (Please look at the attached test if it could be interesting.)<br>
    and came to this issue with a coverage. I tried to play with <span
      class="st">GCOV_PREFIX</span>, but without luck.<br>
    Yesterday I found the more recent discussion:<br>
<a class="moz-txt-link-freetext" href="https://www.postgresql.org/message-id/flat/44ecae53-9861-71b7-1d43-4658acc52519%402ndquadrant.com#d02e2e61212831fbceadf290637913a0">https://www.postgresql.org/message-id/flat/44ecae53-9861-71b7-1d43-4658acc52519%402ndquadrant.com#d02e2e61212831fbceadf290637913a0</a><br>
    (where probably the same problem came out).<br>
    <br>
    Finally I've managed to get an expected coverage when I performed
    $node_standby-&gt;stop() (but __gcov_flush() in
    SignalHandlerForCrashExit() helps too).<br>
    <br>
    Best regards,<br>
    Alexander<br>
  </body>
</html>

--------------38E63F6B61347BA1EB8D3F9C--

--------------1910B4EA4F043C759AC5829B
Content-Type: text/x-patch; charset=UTF-8;
 name="021_indexes-test.patch"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="021_indexes-test.patch"

diff --git a/src/test/recovery/t/021_indexes.pl b/src/test/recovery/t/021_indexes.pl
new file mode 100644
index 0000000000..902133d55a
--- /dev/null
+++ b/src/test/recovery/t/021_indexes.pl
@@ -0,0 +1,102 @@
+# Test testing indexes replication
+use strict;
+use warnings;
+use PostgresNode;
+use TestLib;
+use Test::More tests => 1;
+
+# Initialize master node
+my $node_master = get_new_node('master');
+$node_master->init(allows_streaming => 1);
+$node_master->start;
+
+# Add a table for gist index check
+$node_master->safe_psql('postgres',
+    qq{
+create table gist_point_tbl(id int, p point);
+insert into gist_point_tbl(id, p)
+    select g, point(g*10, g*10) from generate_series(10000, 11000) g;
+create index gist_pointidx on gist_point_tbl using gist(p);});
+
+# Take backup
+my $backup_name = 'my_backup';
+$node_master->backup($backup_name);
+
+# Create streaming standby from backup
+my $node_standby = get_new_node('standby');
+$node_standby->init_from_backup($node_master, $backup_name,
+    has_streaming => 1);
+$node_standby->start;
+
+$node_master->safe_psql('postgres', qq{
+create temp table gist_point_tbl_t(id int, p point);
+create index gist_pointidx_t on gist_point_tbl_t using gist(p);
+insert into gist_point_tbl_t(id, p)
+    select g, point(g*10, g*10) from generate_series(1, 1000) g;
+set enable_seqscan=off;
+set enable_bitmapscan=off;
+explain (costs off)
+select p from gist_point_tbl_t where p <@ box(point(0,0), point(100, 100));
+});
+
+$node_master->safe_psql('postgres', qq{
+create unlogged table gist_point_tbl_u(id int, p point);
+create index gist_pointidx_u on gist_point_tbl_u using gist(p);
+insert into gist_point_tbl_u(id, p)
+    select g, point(g*10, g*10) from generate_series(1, 1000) g;
+set enable_seqscan=off;
+set enable_bitmapscan=off;
+explain (costs off)
+select p from gist_point_tbl_u where p <@ box(point(0,0), point(100, 100));
+});
+
+$node_master->safe_psql('postgres', qq{
+insert into gist_point_tbl (id, p)
+    select g, point(g*10, g*10) from generate_series(1, 1000) g;});
+
+$node_master->safe_psql('postgres', "delete from gist_point_tbl where id < 500");
+
+$node_master->safe_psql('postgres', qq{
+create table test as (select x, box(point(x, x),point(x, x))
+   from generate_series(1,4000000) as x);
+
+create index test_idx on test using gist (box);
+
+set enable_seqscan TO false;
+set enable_bitmapscan TO false;
+
+delete from test where box && box(point(0,0), point(100000,100000));
+
+-- This query invokes gistkillitems()
+select count(box) from test where box && box(point(0,0), point(100000,100000));
+});
+
+$node_master->safe_psql('postgres', qq{
+insert into test
+    select x, box(point(x, x),point(x*3, x*3))
+    from generate_series(1,200000) as x;});
+
+$node_master->safe_psql('postgres', qq{
+update test set box = box where x<2000000; vacuum test;});
+$node_master->safe_psql('postgres', qq{
+delete from test where x<1000000; vacuum test;});
+$node_master->safe_psql('postgres', qq{
+insert into test
+    select x, box(point(x, x),point(x, x))
+    from generate_series(1,1000000) as x;});
+
+$node_master->safe_psql('postgres', qq{
+insert into gist_point_tbl (id, p)
+    select g,        point(g*5, g*5) from generate_series(1, 10000) g;});
+
+$node_master->wait_for_catchup($node_standby, 'replay');
+
+my $result = $node_standby->safe_psql('postgres', qq{
+set enable_seqscan=off;
+set enable_bitmapscan=off;
+explain (costs off)
+select p from gist_point_tbl where p <@ box(point(0,0), point(100, 100));});
+ok($result =~ /^Index Only Scan using gist_pointidx/, "gist index used on a standby");
+
+#$node_standby->stop();
+#$node_master->stop();

--------------1910B4EA4F043C759AC5829B--