Re: Intermittent buildfarm failures on wrasse

Hi,

On April 15, 2022 11:12:10 AM EDT, Andres Freund <andres(at)anarazel(dot)de> wrote:
>Hi,
>
>On 2022-04-15 10:15:32 -0400, Tom Lane wrote:
>> The morning's first result is that during a failing run,
>> the vacuum in test_setup sees
>>
>> 2022-04-15 16:01:43.064 CEST [4436:75] pg_regress/test_setup LOG: statement: VACUUM ANALYZE tenk1;
>> 2022-04-15 16:01:43.064 CEST [4436:76] pg_regress/test_setup LOG: vacuuming "regression.public.tenk1"
>> 2022-04-15 16:01:43.064 CEST [4436:77] pg_regress/test_setup STATEMENT: VACUUM ANALYZE tenk1;
>> 2022-04-15 16:01:43.071 CEST [4436:78] pg_regress/test_setup LOG: finished vacuuming "regression.public.tenk1": index scans: 0
>> pages: 0 removed, 345 remain, 345 scanned (100.00% of total)
>> tuples: 0 removed, 10000 remain, 0 are dead but not yet removable
>> removable cutoff: 724, older by 26 xids when operation ended
>> index scan not needed: 0 pages from table (0.00% of total) had 0 dead item identifiers removed
>> avg read rate: 2.189 MB/s, avg write rate: 2.189 MB/s
>> buffer usage: 695 hits, 2 misses, 2 dirtied
>> WAL usage: 1 records, 0 full page images, 188 bytes
>> system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
>> 2022-04-15 16:01:43.071 CEST [4436:79] pg_regress/test_setup STATEMENT: VACUUM ANALYZE tenk1;
>
>The horizon advancing by 26 xids during tenk1's vacuum seems like quite
>a bit, given there's no normal concurrent activity during test_setup.
>
>
>> In fact, right after initdb pg_controldata shows
>> Latest checkpoint's NextXID: 0:724
>> Latest checkpoint's oldestXID: 716
>
>So that's the xmin that e.g. the autovac launcher ends up with during
>start...
>
>If I make get_database_list() sleep for 5s within the scan, I can
>reproduce on x86-64.

Off for a bit, but I realized that we likely don't exclude the launcher because it's not database associated...

--
Sent from my Android device with K-9 Mail. Please excuse my brevity.