From: Tom Lane <tgl@sss.pgh.pa.us>
To: Michael Paquier <michael@paquier.xyz>
cc: Andrew Dunstan <andrew.dunstan@2ndquadrant.com>,
        Andres Freund <andres@anarazel.de>,
        Peter Eisentraut <peter.eisentraut@2ndquadrant.com>,
        Yuli Khodorkovskiy <yuli.khodorkovskiy@crunchydata.com>,
        pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #15804: Assertion failure when using logging_collector with
 EXEC_BACKEND
In-reply-to: <7927.1558364465@sss.pgh.pa.us>
References: <20190516060628.GE1415@paquier.xyz>
 <20190517042536.GM20887@paquier.xyz>
 <20190517202443.gw4zdfkpwgsjdel6@alap3.anarazel.de>
 <20190518093522.GA19212@paquier.xyz> <28565.1558196308@sss.pgh.pa.us>
 <20190519004344.GA3653@paquier.xyz> <22995.1558278322@sss.pgh.pa.us>
 <27719.1558282181@sss.pgh.pa.us>
 <16df9d01-8b03-2664-a18c-16c40186f5ab@2ndQuadrant.com>
 <2702.1558289980@sss.pgh.pa.us> <20190520012728.GC1923@paquier.xyz>
 <1664.1558325417@sss.pgh.pa.us> <7927.1558364465@sss.pgh.pa.us>
Comments: In-reply-to Tom Lane <tgl@sss.pgh.pa.us>
	message dated "Mon, 20 May 2019 11:01:05 -0400"
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="----- =_aaaaaaaaaa0"
Content-ID: <31435.1568057708.0@sss.pgh.pa.us>
Date: Mon, 09 Sep 2019 15:35:23 -0400
Message-ID: <31457.1568057723@sss.pgh.pa.us>
Precedence: bulk

------- =_aaaaaaaaaa0
Content-Type: text/plain; charset="us-ascii"
Content-ID: <31435.1568057708.1@sss.pgh.pa.us>

I wrote:
> In other words, the right way to think about this is less "move
> syslogger launch to earlier" and more "move port opening to later".

> I did some cursory testing of that idea with the attached patch,
> which simply relocates the port opening logic to below where
> syslogger start is (though "git diff" insists on presenting it
> differently :-().  I also moved and recommented the emission
> of the "starting ..." log entry.

The cfbot noticed that this required a minor rebase over 7de19fbc0,
so here is one.

> One issue with this is that we can't be sure we have sole control
> of the postmaster port number at the time we create shmem.
> Hence, to avoid undesirable conflicts of shmem, we should change
> things to base the shmem key on the datadir's ID not the port
> number, as was already speculated about in
> https://postgr.es/m/16908.1557521200@sss.pgh.pa.us

That's now been committed (7de19fbc0), so it's not holding back
this patch anymore.

> Also, this will change the order in which entries get made into
> postmaster.pid.  I think that's OK, but we'll need to take a
> close look at pg_ctl to be sure it isn't making any invalid
> assumptions.

I took a look around and couldn't find any such problems.
pg_ctl, in particular, doesn't care about the order in which
these lines get added.  I did add a comment to pidfile.h
warning people against making new assumptions in this area.

> There may be some other reorderings that would be a good idea.
> In particular I'm thinking that the CreateOptsFile call should
> be pushed down, so that it doesn't get written until we know
> that the port number is OK.

I did that here, too.

I think this probably is committable now, though of course it'd
be good for somebody to review it (and maybe test on Windows
before it hits the buildfarm?)

			regards, tom lane


------- =_aaaaaaaaaa0
Content-Type: text/x-diff; name="postpone-port-opening-2.patch";
	charset="us-ascii"
Content-ID: <31435.1568057708.2@sss.pgh.pa.us>
Content-Description: postpone-port-opening-2.patch
Content-Transfer-Encoding: quoted-printable

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/=
postmaster.c
index a5446d5..6941159 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -993,7 +993,133 @@ PostmasterMain(int argc, char *argv[])
 	 */
 	InitializeMaxBackends();
 =

-	/* Report server startup in log */
+	/*
+	 * Set up shared memory and semaphores.
+	 */
+	reset_shared();
+
+	/*
+	 * Estimate number of openable files.  This must happen after setting up
+	 * semaphores, because on some platforms semaphores count as open files.
+	 */
+	set_max_safe_fds();
+
+	/*
+	 * Set reference point for stack-depth checking.
+	 */
+	set_stack_base();
+
+	/*
+	 * Initialize pipe (or process handle on Windows) that allows children t=
o
+	 * wake up from sleep on postmaster death.
+	 */
+	InitPostmasterDeathWatchHandle();
+
+#ifdef WIN32
+
+	/*
+	 * Initialize I/O completion port used to deliver list of dead children.
+	 */
+	win32ChildQueue =3D CreateIoCompletionPort(INVALID_HANDLE_VALUE, NULL, 0=
, 1);
+	if (win32ChildQueue =3D=3D NULL)
+		ereport(FATAL,
+				(errmsg("could not create I/O completion port for child queue")));
+#endif
+
+#ifdef EXEC_BACKEND
+	/* Write out nondefault GUC settings for child processes to use */
+	write_nondefault_variables(PGC_POSTMASTER);
+#endif
+
+	/*
+	 * Write the external PID file if requested
+	 */
+	if (external_pid_file)
+	{
+		FILE	   *fpidfile =3D fopen(external_pid_file, "w");
+
+		if (fpidfile)
+		{
+			fprintf(fpidfile, "%d\n", MyProcPid);
+			fclose(fpidfile);
+
+			/* Make PID file world readable */
+			if (chmod(external_pid_file, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH) !=3D=
 0)
+				write_stderr("%s: could not change permissions of external PID file \=
"%s\": %s\n",
+							 progname, external_pid_file, strerror(errno));
+		}
+		else
+			write_stderr("%s: could not write external PID file \"%s\": %s\n",
+						 progname, external_pid_file, strerror(errno));
+
+		on_proc_exit(unlink_external_pid_file, 0);
+	}
+
+	/*
+	 * Remove old temporary files.  At this point there can be no other
+	 * Postgres processes running in this directory, so this should be safe.
+	 */
+	RemovePgTempFiles();
+
+	/*
+	 * Forcibly remove the files signaling a standby promotion request.
+	 * Otherwise, the existence of those files triggers a promotion too earl=
y,
+	 * whether a user wants that or not.
+	 *
+	 * This removal of files is usually unnecessary because they can exist
+	 * only during a few moments during a standby promotion. However there i=
s
+	 * a race condition: if pg_ctl promote is executed and creates the files
+	 * during a promotion, the files can stay around even after the server i=
s
+	 * brought up to new master. Then, if new standby starts by using the
+	 * backup taken from that master, the files can exist at the server
+	 * startup and should be removed in order to avoid an unexpected
+	 * promotion.
+	 *
+	 * Note that promotion signal files need to be removed before the startu=
p
+	 * process is invoked. Because, after that, they can be used by
+	 * postmaster's SIGUSR1 signal handler.
+	 */
+	RemovePromoteSignalFiles();
+
+	/* Do the same for logrotate signal file */
+	RemoveLogrotateSignalFiles();
+
+	/* Remove any outdated file holding the current log filenames. */
+	if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno !=3D ENOENT)
+		ereport(LOG,
+				(errcode_for_file_access(),
+				 errmsg("could not remove file \"%s\": %m",
+						LOG_METAINFO_DATAFILE)));
+
+	/*
+	 * If enabled, start up syslogger collection subprocess
+	 */
+	SysLoggerPID =3D SysLogger_Start();
+
+	/*
+	 * Reset whereToSendOutput from DestDebug (its starting state) to
+	 * DestNone. This stops ereport from sending log messages to stderr unle=
ss
+	 * Log_destination permits.  We don't do this until the postmaster is
+	 * fully launched, since startup failures may as well be reported to
+	 * stderr.
+	 *
+	 * If we are in fact disabling logging to stderr, first emit a log messa=
ge
+	 * saying so, to provide a breadcrumb trail for users who may not rememb=
er
+	 * that their logging is configured to go somewhere else.
+	 */
+	if (!(Log_destination & LOG_DESTINATION_STDERR))
+		ereport(LOG,
+				(errmsg("ending log output to stderr"),
+				 errhint("Future log output will go to log destination \"%s\".",
+						 Log_destination_string)));
+
+	whereToSendOutput =3D DestNone;
+
+	/*
+	 * Report server startup in log.  While we could emit this much earlier,
+	 * it seems best to do so after starting the log collector, if we intend
+	 * to use one.
+	 */
 	ereport(LOG,
 			(errmsg("starting %s", PG_VERSION_STR)));
 =

@@ -1173,134 +1299,12 @@ PostmasterMain(int argc, char *argv[])
 		AddToDataDirLockFile(LOCK_FILE_LINE_LISTEN_ADDR, "");
 =

 	/*
-	 * Set up shared memory and semaphores.
-	 */
-	reset_shared();
-
-	/*
-	 * Estimate number of openable files.  This must happen after setting up
-	 * semaphores, because on some platforms semaphores count as open files.
-	 */
-	set_max_safe_fds();
-
-	/*
-	 * Set reference point for stack-depth checking.
-	 */
-	set_stack_base();
-
-	/*
-	 * Initialize pipe (or process handle on Windows) that allows children t=
o
-	 * wake up from sleep on postmaster death.
-	 */
-	InitPostmasterDeathWatchHandle();
-
-#ifdef WIN32
-
-	/*
-	 * Initialize I/O completion port used to deliver list of dead children.
-	 */
-	win32ChildQueue =3D CreateIoCompletionPort(INVALID_HANDLE_VALUE, NULL, 0=
, 1);
-	if (win32ChildQueue =3D=3D NULL)
-		ereport(FATAL,
-				(errmsg("could not create I/O completion port for child queue")));
-#endif
-
-	/*
 	 * Record postmaster options.  We delay this till now to avoid recording
-	 * bogus options (eg, NBuffers too high for available memory).
+	 * bogus options (eg, unusable port number).
 	 */
 	if (!CreateOptsFile(argc, argv, my_exec_path))
 		ExitPostmaster(1);
 =

-#ifdef EXEC_BACKEND
-	/* Write out nondefault GUC settings for child processes to use */
-	write_nondefault_variables(PGC_POSTMASTER);
-#endif
-
-	/*
-	 * Write the external PID file if requested
-	 */
-	if (external_pid_file)
-	{
-		FILE	   *fpidfile =3D fopen(external_pid_file, "w");
-
-		if (fpidfile)
-		{
-			fprintf(fpidfile, "%d\n", MyProcPid);
-			fclose(fpidfile);
-
-			/* Make PID file world readable */
-			if (chmod(external_pid_file, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH) !=3D=
 0)
-				write_stderr("%s: could not change permissions of external PID file \=
"%s\": %s\n",
-							 progname, external_pid_file, strerror(errno));
-		}
-		else
-			write_stderr("%s: could not write external PID file \"%s\": %s\n",
-						 progname, external_pid_file, strerror(errno));
-
-		on_proc_exit(unlink_external_pid_file, 0);
-	}
-
-	/*
-	 * Remove old temporary files.  At this point there can be no other
-	 * Postgres processes running in this directory, so this should be safe.
-	 */
-	RemovePgTempFiles();
-
-	/*
-	 * Forcibly remove the files signaling a standby promotion request.
-	 * Otherwise, the existence of those files triggers a promotion too earl=
y,
-	 * whether a user wants that or not.
-	 *
-	 * This removal of files is usually unnecessary because they can exist
-	 * only during a few moments during a standby promotion. However there i=
s
-	 * a race condition: if pg_ctl promote is executed and creates the files
-	 * during a promotion, the files can stay around even after the server i=
s
-	 * brought up to new master. Then, if new standby starts by using the
-	 * backup taken from that master, the files can exist at the server
-	 * startup and should be removed in order to avoid an unexpected
-	 * promotion.
-	 *
-	 * Note that promotion signal files need to be removed before the startu=
p
-	 * process is invoked. Because, after that, they can be used by
-	 * postmaster's SIGUSR1 signal handler.
-	 */
-	RemovePromoteSignalFiles();
-
-	/* Do the same for logrotate signal file */
-	RemoveLogrotateSignalFiles();
-
-	/* Remove any outdated file holding the current log filenames. */
-	if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno !=3D ENOENT)
-		ereport(LOG,
-				(errcode_for_file_access(),
-				 errmsg("could not remove file \"%s\": %m",
-						LOG_METAINFO_DATAFILE)));
-
-	/*
-	 * If enabled, start up syslogger collection subprocess
-	 */
-	SysLoggerPID =3D SysLogger_Start();
-
-	/*
-	 * Reset whereToSendOutput from DestDebug (its starting state) to
-	 * DestNone. This stops ereport from sending log messages to stderr unle=
ss
-	 * Log_destination permits.  We don't do this until the postmaster is
-	 * fully launched, since startup failures may as well be reported to
-	 * stderr.
-	 *
-	 * If we are in fact disabling logging to stderr, first emit a log messa=
ge
-	 * saying so, to provide a breadcrumb trail for users who may not rememb=
er
-	 * that their logging is configured to go somewhere else.
-	 */
-	if (!(Log_destination & LOG_DESTINATION_STDERR))
-		ereport(LOG,
-				(errmsg("ending log output to stderr"),
-				 errhint("Future log output will go to log destination \"%s\".",
-						 Log_destination_string)));
-
-	whereToSendOutput =3D DestNone;
-
 	/*
 	 * Initialize stats collection subsystem (this does NOT start the
 	 * collector process!)
diff --git a/src/include/utils/pidfile.h b/src/include/utils/pidfile.h
index b2dcca6..21e7ccf 100644
--- a/src/include/utils/pidfile.h
+++ b/src/include/utils/pidfile.h
@@ -28,7 +28,8 @@
  *
  * Lines 6 and up are added via AddToDataDirLockFile() after initial file
  * creation; also, line 5 is initially empty and is changed after the fir=
st
- * Unix socket is opened.
+ * Unix socket is opened.  Onlookers should not assume that lines 4 and u=
p
+ * are filled in any particular order.
  *
  * Socket lock file(s), if used, have the same contents as lines 1-5, wit=
h
  * line 5 being their own directory.

------- =_aaaaaaaaaa0--