Re: test_autovacuum/001_parallel_autovacuum is broken - Mailing list pgsql-hackers

From Masahiko Sawada
Subject Re: test_autovacuum/001_parallel_autovacuum is broken
Date
Msg-id CAD21AoCj=OSxoh3RBw0VWJ7Y7c9EipRhpatcZaHuXKGLWyKgdQ@mail.gmail.com
Whole thread
In response to Re: test_autovacuum/001_parallel_autovacuum is broken  (Alexander Lakhin <exclusion@gmail.com>)
Responses Re: test_autovacuum/001_parallel_autovacuum is broken
List pgsql-hackers
On Thu, Apr 9, 2026 at 11:00 AM Alexander Lakhin <exclusion@gmail.com> wrote:
>
> 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.plline 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?
>

Thank you for the report.

The root cause seems to me that it's not guaranteed that we can see
the autovacuum logs after checking the statistics (i.e.,
pg_stat_user_tables) as we update the statistics and then write the
log.

One way to fix the test is to replace log_contains() with
wait_for_log(). We can also remove wait_for_autovacuum_complete()
logic altogether.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com



pgsql-hackers by date:

Previous
From: Sami Imseih
Date:
Subject: Re: test_autovacuum/001_parallel_autovacuum is broken
Next
From: Sami Imseih
Date:
Subject: Re: test_autovacuum/001_parallel_autovacuum is broken