Content-Type: multipart/alternative;
 boundary="------------rymO0l9MVXTDK5yRekAtfKNb"
Message-ID: <525d0f48-93f7-493f-a988-f39b460a79bc@gmail.com>
Date: Thu, 9 Apr 2026 21:00:00 +0300
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Subject: Re: test_autovacuum/001_parallel_autovacuum is broken
To: Sami Imseih <samimseih@gmail.com>,
 pgsql-hackers <pgsql-hackers@postgresql.org>
Cc: Masahiko Sawada <sawada.mshk@gmail.com>,
 Daniil Davydov <3danissimo@gmail.com>
References: 
 <CAA5RZ0s+kZZRMSF4HW7tZ9W2jS1o4B+Fg8dr5a-T6mANX+mdQA@mail.gmail.com>
Content-Language: en-US
From: Alexander Lakhin <exclusion@gmail.com>
In-Reply-To: 
 <CAA5RZ0s+kZZRMSF4HW7tZ9W2jS1o4B+Fg8dr5a-T6mANX+mdQA@mail.gmail.com>
Archived-At: 
 <https://www.postgresql.org/message-id/525d0f48-93f7-493f-a988-f39b460a79bc%40gmail.com>
Precedence: bulk

This is a multi-part message in MIME format.
--------------rymO0l9MVXTDK5yRekAtfKNb
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit

Hello,

07.04.2026 05:23, Sami Imseih wrote:
> I noticed that the test introduced in parallel autovacuum in 1ff3180ca01 was
> very slow, but eventually succeeded. I tracked it down to the point in
> the test that is waiting for "parallel autovacuum worker updated cost params".

I've found another issue with the test manifested on buildfarm, at least
at [1]:
[06:54:07.738](4.121s) not ok 1
[06:54:07.769](0.031s) #   Failed test at 
/home/bf/bf-build/flaviventris/HEAD/pgsql/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl line 133.
### Stopping node "main" using mode fast

The corresponding test code:
# Wait until the parallel autovacuum on table is completed. At the same time,
# we check that the required number of parallel workers has been started.
wait_for_autovacuum_complete($node, $av_count);
ok( $node->log_contains(
         qr/parallel workers: index vacuum: 2 planned, 2 launched in total/,
         $log_offset));

but regress_log_001_parallel_autovacuum contains this string:
2026-04-07 06:54:07.736 CEST [1825954][autovacuum worker][102/5:0] LOG:  automatic vacuum of table 
"postgres.public.test_autovac": index scans: 1
...
     parallel workers: index vacuum: 2 planned, 2 launched in total

though the timestamp difference is only 2 ms. I tried the following
modification:
@@ -1222,6 +1222,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
                               (double) dead_items_max_bytes / (1024 * 1024));
              appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));

+pg_usleep(300000);
              ereport(verbose ? INFO : LOG,
                      (errmsg_internal("%s", buf.data)));
              pfree(buf.data);

and it makes the test fail for me on each run.
Could you please look if this can be fixed too?

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=flaviventris&dt=2026-04-07%2004%3A41%3A09

Best regards,
Alexander
--------------rymO0l9MVXTDK5yRekAtfKNb
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: 8bit

<!DOCTYPE html>
<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
  </head>
  <body>
    <div class="moz-cite-prefix">Hello,<br>
      <br>
      07.04.2026 05:23, Sami Imseih wrote:<span
      style="white-space: pre-wrap">
</span></div>
    <blockquote type="cite"
cite="mid:CAA5RZ0s+kZZRMSF4HW7tZ9W2jS1o4B+Fg8dr5a-T6mANX+mdQA@mail.gmail.com">
      <pre wrap="" class="moz-quote-pre">I noticed that the test introduced in parallel autovacuum in 1ff3180ca01 was
very slow, but eventually succeeded. I tracked it down to the point in
the test that is waiting for "parallel autovacuum worker updated cost params".
</pre>
    </blockquote>
    <br>
    I've found another issue with the test manifested on buildfarm, at
    least<br>
    at [1]:<br>
    [06:54:07.738](4.121s) not ok 1<br>
    [06:54:07.769](0.031s) #   Failed test at
/home/bf/bf-build/flaviventris/HEAD/pgsql/src/test/modules/test_autovacuum/t/001_parallel_autovacuum.pl
    line 133.<br>
    ### Stopping node "main" using mode fast<br>
    <br>
    The corresponding test code:<br>
    # Wait until the parallel autovacuum on table is completed. At the
    same time,<br>
    # we check that the required number of parallel workers has been
    started.<br>
    wait_for_autovacuum_complete($node, $av_count);<br>
    ok( $node-&gt;log_contains(<br>
            qr/parallel workers: index vacuum: 2 planned, 2 launched in
    total/,<br>
            $log_offset));<br>
    <br>
    but regress_log_001_parallel_autovacuum contains this string:<br>
    2026-04-07 06:54:07.736 CEST [1825954][autovacuum worker][102/5:0]
    LOG:  automatic vacuum of table "postgres.public.test_autovac":
    index scans: 1<br>
    ...<br>
        parallel workers: index vacuum: 2 planned, 2 launched in total<br>
    <br>
    though the timestamp difference is only 2 ms. I tried the following<br>
    modification:<br>
    @@ -1222,6 +1222,7 @@ heap_vacuum_rel(Relation rel, const
    VacuumParams *params,<br>
                                  (double) dead_items_max_bytes / (1024
    * 1024));<br>
                 appendStringInfo(&amp;buf, _("system usage: %s"),
    pg_rusage_show(&amp;ru0));<br>
     <br>
    +pg_usleep(300000);<br>
                 ereport(verbose ? INFO : LOG,<br>
                         (errmsg_internal("%s", buf.data)));<br>
                 pfree(buf.data);<br>
    <br>
    and it makes the test fail for me on each run.<br>
    Could you please look if this can be fixed too?<br>
    <br>
    [1]
<a class="moz-txt-link-freetext" href="https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=flaviventris&amp;dt=2026-04-07%2004%3A41%3A09">https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=flaviventris&amp;dt=2026-04-07%2004%3A41%3A09</a><br>
    <br>
    Best regards,<br>
    Alexander<br>
  </body>
</html>

--------------rymO0l9MVXTDK5yRekAtfKNb--