From: Tom Lane <tgl@sss.pgh.pa.us>
To: Noah Misch <noah@leadboat.com>
Cc: Andres Freund <andres@anarazel.de>
Cc: Thomas Munro <thomas.munro@gmail.com>
Cc: pgsql-committers <pgsql-committers@lists.postgresql.org>
Subject: Re: pgsql: TAP tests: check for postmaster.pid anyway when "pg_ctl start" f
Date: Thu, 10 Feb 2022 14:58:57 -0500
Message-ID: <1709793.1644523137@sss.pgh.pa.us> (raw)
In-Reply-To: <20220210023537.GA3222837@rfd.leadboat.com>
References: <E1nAIWI-0006et-HW@gemulon.postgresql.org>
<CA+hUKGKV6fOHvfiPt8=dOKzvswjAyLoFoJF1iQXMNpi7+hD1JQ@mail.gmail.com>
<855583.1642687119@sss.pgh.pa.us>
<867290.1642689136@sss.pgh.pa.us>
<20220120192736.msyesvdlljn6tptw@alap3.anarazel.de>
<926839.1642708567@sss.pgh.pa.us>
<1075553.1642717844@sss.pgh.pa.us>
<20220210023537.GA3222837@rfd.leadboat.com>
Noah Misch <noah@leadboat.com> writes:
> On AIX, this pair of commits added 5-10h of runtime to 017_shm.pl.
I poked into this on gcc119 (hoverfly's host). As best I can tell,
the root of the problem is that "kill 9" isn't instantaneous on this
platform. In [1] we find this in 017_shm_gnat.log:
2022-02-10 07:08:20.175 UTC [41615696:1] LOG: starting PostgreSQL 15devel on powerpc-ibm-aix7.2.4.0, compiled by /opt/IBM/xlc/16.1.0/bin/xlc_r -D_LARGE_FILES=1 -DRANDOMIZE_ALLOCATED_MEMORY, 64-bit
2022-02-10 07:08:20.175 UTC [41615696:2] LOG: listening on Unix socket "/home/nm/farm/tmp/FTwLLIVrmg/.s.PGSQL.63971"
2022-02-10 07:08:20.182 UTC [34931288:1] LOG: database system was shut down at 2022-02-10 07:08:20 UTC
2022-02-10 07:08:20.194 UTC [41615696:3] LOG: database system is ready to accept connections
2022-02-10 07:08:20.380 UTC [26018140:1] FATAL: lock file "postmaster.pid" already exists
2022-02-10 07:08:20.380 UTC [26018140:2] HINT: Is another postmaster (PID 41615696) running in data directory "/scratch/nm/farm/xlc64v16/HEAD/pgsql.build/src/test/recovery/tmp_check/t_017_shm_gnat_data/pgdata"?
2022-02-10 12:48:44.665 UTC [18350518:1] LOG: starting PostgreSQL 15devel on powerpc-ibm-aix7.2.4.0, compiled by /opt/IBM/xlc/16.1.0/bin/xlc_r -D_LARGE_FILES=1 -DRANDOMIZE_ALLOCATED_MEMORY, 64-bit
41615696 is the postmaster PID that is targeted by 017_shm.pl's first
kill9 call, after which we immediately attempt to start a new postmaster
(26018140), which is complaining that 41615696 is still alive. Looking
at the code that issues that in miscinit.c, either kill(41615696, 0)
succeeded, or it returned some errno that's neither ESRCH nor EPERM.
AIX doesn't document any kill(2) errors outside of what POSIX says,
so I reject the second theory and conclude that kill() was still seeing
41615696 as alive at this point.
But, once the replacement postmaster fails, we got trouble, because
the old postmaster.pid file (mentioning 41615696) is still there.
017_shm.pl's poll_start sees that "pg_ctl start" failed but then
does
# Clean up in case the start attempt just timed out or some such.
$node->stop('fast', fail_ok => 1);
(which I added in 4fdbf9af5).
My hypothesis is that the kill() call in pg_ctl's do_stop() still sees
41615696 as alive at this point, so pg_ctl enters a loop of waiting for
postmaster.pid to go away, which it never will. PGCTLTIMEOUT later
(~18000 seconds for hoverfly), pg_ctl gives up and the test proceeds.
So it looks to me like the core problem is that pg_ctl's do_stop()
is too trusting: if it once sees the postmaster PID as alive, it
figures that's the end of the story. We need to modify it to
recheck that during the wait loop. (do_restart and do_promote
seem similarly naive ... and why are there so many copies of the
wait loop, anyway?)
Another idea is to modify Cluster.pm's kill9 to not return until the
PID is gone according to kill(0). On the other hand, that'd mask
problems like this, so I'm not entirely enthused about changing
that end of things.
regards, tom lane
[1] https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=hoverfly&dt=2022-02-10%2006%3A29%3...
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-committers@postgresql.org
Cc: tgl@sss.pgh.pa.us, noah@leadboat.com, andres@anarazel.de, thomas.munro@gmail.com, pgsql-committers@lists.postgresql.org
Subject: Re: pgsql: TAP tests: check for postmaster.pid anyway when "pg_ctl start" f
In-Reply-To: <1709793.1644523137@sss.pgh.pa.us>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox