From: Tom Lane <tgl@sss.pgh.pa.us>
To: Alexander Lakhin <exclusion@gmail.com>
cc: Justin Pryzby <pryzby@telsasoft.com>,
        pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: More time spending with "delete pending"
In-reply-to: <995713.1605725597@sss.pgh.pa.us>
References: <c3427edf-d7c0-ff57-90f6-b5de3bb62709@gmail.com>
 <20201115011112.GW30691@telsasoft.com>
 <979f4ee6-9960-e37f-f3ee-f458e87777b0@gmail.com>
 <995713.1605725597@sss.pgh.pa.us>
Comments: In-reply-to Tom Lane <tgl@sss.pgh.pa.us>
	message dated "Wed, 18 Nov 2020 13:53:17 -0500"
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-ID: <1001774.1605731995.1@sss.pgh.pa.us>
Content-Transfer-Encoding: quoted-printable
Date: Wed, 18 Nov 2020 15:39:55 -0500
Message-ID: <1001775.1605731995@sss.pgh.pa.us>
Precedence: bulk

BTW ... scraping the buildfarm logs for "could not open ... Permission
denied" failures suggests that pgwin32_open() isn't the pinnacle of
perfection either.  In the last three months I found these instances:

 dory      | REL_11_STABLE | 2020-08-21 22:15:14 | Check              | pg=
_ctl: could not open PID file "C:/pgbuildfarm/pgbuildroot/REL_11_STABLE/pg=
sql.build/src/test/regress/./tmp_check/data/postmaster.pid": Permission de=
nied\r
 fairywren | REL_11_STABLE | 2020-09-01 01:04:55 | Check              | pg=
_ctl: could not open PID file "C:/tools/msys64/home/pgrunner/bf/root/REL_1=
1_STABLE/pgsql.build/src/test/regress/./tmp_check/data/postmaster.pid": Pe=
rmission denied\r
 dory      | HEAD          | 2020-09-16 02:40:17 | Check              | pg=
_ctl: could not open PID file "C:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build=
/src/test/regress/./tmp_check/data/postmaster.pid": Permission denied\r
 walleye   | HEAD          | 2020-09-29 18:35:46 | pg_upgradeCheck    | 20=
20-09-29 15:20:04.298 EDT [896:31] pg_regress/gist WARNING:  could not ope=
n statistics file "pg_stat_tmp/global.stat": Permission denied
 frogmouth | REL_10_STABLE | 2020-10-01 00:30:15 | StopDb-C:5         | wa=
iting for server to shut down....pg_ctl: could not open PID file "data-C/p=
ostmaster.pid": Permission denied\r
 dory      | REL_11_STABLE | 2020-10-05 02:15:06 | pg_upgradeCheck    | wa=
iting for server to shut down..............pg_ctl: could not open PID file=
 "C:/pgbuildfarm/pgbuildroot/REL_11_STABLE/pgsql.build/src/bin/pg_upgrade/=
tmp_check/data.old/postmaster.pid": Permission denied\r
 bowerbird | REL_10_STABLE | 2020-10-21 23:19:22 | scriptsCheck       | wa=
iting for server to shut down....pg_ctl: could not open PID file "H:/prog/=
bf/root/REL_10_STABLE/pgsql.build/src/bin/scripts/tmp_check/data_main_cH68=
/pgdata/postmaster.pid": Permission denied\r
 jacana    | REL_10_STABLE | 2020-10-22 12:42:51 | pg_upgradeCheck    | Oc=
t 22 09:08:20 waiting for server to shut down....pg_ctl: could not open PI=
D file "c:/mingw/msys/1.0/home/pgrunner/bf/root/REL_10_STABLE/pgsql.build/=
src/bin/pg_upgrade/tmp_check/data.old/postmaster.pid": Permission denied\r
 dory      | HEAD          | 2020-10-22 23:30:16 | Check              | pg=
_ctl: could not open PID file "C:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build=
/src/test/regress/./tmp_check/data/postmaster.pid": Permission denied\r
 dory      | REL_11_STABLE | 2020-10-27 18:15:08 | StopDb-C:2         | wa=
iting for server to shut down....pg_ctl: could not open PID file "data-C/p=
ostmaster.pid": Permission denied\r
 fairywren | REL_11_STABLE | 2020-10-28 04:01:17 | recoveryCheck      | wa=
iting for server to shut down....pg_ctl: could not open PID file "C:/tools=
/msys64/home/pgrunner/bf/root/REL_11_STABLE/pgsql.build/src/test/recovery/=
tmp_check/t_004_timeline_switch_standby_2_data/pgdata/postmaster.pid": Per=
mission denied\r
 hamerkop  | REL_11_STABLE | 2020-11-01 11:31:54 | pg_upgradeCheck    | wa=
iting for server to shut down....pg_ctl: could not open PID file "c:/build=
-farm-local/buildroot/REL_11_STABLE/pgsql.build/src/bin/pg_upgrade/tmp_che=
ck/data/postmaster.pid": Permission denied\r
 dory      | HEAD          | 2020-11-04 05:50:17 | Check              | pg=
_ctl: could not open PID file "C:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build=
/src/test/regress/./tmp_check/data/postmaster.pid": Permission denied\r
 walleye   | HEAD          | 2020-11-09 09:45:41 | Check              | 20=
20-11-09 05:06:19.672 EST [4408:31] pg_regress/gist WARNING:  could not op=
en statistics file "pg_stat_tmp/global.stat": Permission denied
 dory      | HEAD          | 2020-11-10 23:35:18 | Check              | pg=
_ctl: could not open PID file "C:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build=
/src/test/regress/./tmp_check/data/postmaster.pid": Permission denied\r

Now, the ones on the 10 and 11 branches are all from pg_ctl, which
does not use pgwin32_open() in those branches, only native open().
So those aren't fair to count against it.  But we have nearly as
many similar failures in HEAD, which surely is going through
pgwin32_open().  So either we don't really have adequate protection
against delete-pending files, or there is some other effect we haven't
explained yet.

A simple theory about that is that the 1-second wait is not always
enough on heavily loaded buildfarm machines.  Is it sensible to
increase the timeout?

			regards, tom lane